[DevLog]24Q3P1 - Optimize PTA With Thread Affinity

导言

QCC(Quality Control Cycle) 自发的改进效率。

Situation：

工作感觉进度缓慢，
目标不明确，思路不清楚，
回顾时难点/耗时点不记得，不知道如何改进。
测试研究讲究师出有名，有理有据。并不是一味的看结果好就行。如果解释不清楚原因，好结果就无法保持与迁移。

Target：细化项目开发日志记录到一个Tomato周期，

Action：

明确当前阶段目标/剩余目标。
每天细化到半个小时，上午5~6个，下午7~8个，晚上3~5个。
AAR(After Action Review)每天总结难点、达成目标、下一阶段目标。

240923¶

上午

T1: 硬装回来，编译与环境复原，代码同步。
T2: 问题：cpprinter编译错误 - 有额外的构造函数未定义。
1. 使用nm查看了声明和调用文件的.o文件的函数，发现不匹配，推测是使用时的__FUNCTION__参数类型不匹配。
T3：修复：重新编译。
T4：发现参数虽然都是std::string，但是由于库不匹配，所以还是构造函数还是不match，尝试将参数改成更简单的char *,重新编译。

下午

T1&2: 问题：Bus error (core dumped)
1. gdb发现是tIC的多线程内存管理的问题，注释掉相关代码，重新编译。
T3: 问题：SegFault
1. gdb发现是类CallTrace（内部有static变量）指针的delete报错，虽然不是特别理解，但是改用unique智能指针。
T4: unique还是segfault，改成shared_ptr
T5: shared_ptr还是segfault，CallTrack类只是为了包装一下，其实都可以static，所以把指针改成static
T6: 能运行小例子了，但是functionName是乱码，并且start时间是1970-01-04。看上去是析构的时候，这两个变量的值丢失了导致的，但是奇怪的是cmake的例子没有这个问题？
1. static变量解决这个问题

晚上

T1&T2: 精简了stack，
T3：分析线程，发现现象有待研究
T4：[x] OpenSora无法运行，torch的run_backward报错result.use_count() <= 1。回到硬装前留下的问题了。稍微看了对应的代码，是codegen的部分的。
1. 是DEBUG选项的问题。

困难：PTA编译过于缓慢，要15到20分钟

对于修改一个文件的情况，

文件属于libtorch_npu.so,所以查看makefile，发现cmake自动有torch_npu/fast选项
make torch_npu/fast 生成新target
手动安装cp build/package/xxx/xxx.so /anaconda/xxx/xxx.so

达成阶段目标

跑通PTA+cpprinter的代码，
并通过小例子的PTA的各线程调用情况，

To do

测试其他场景OpenSora会不会失败，逐步回退修改：
1. 测试[失败]：怡文原本的选项
2. 测试：baichuan和llama
3. 重编[失败]：删除插入的两处cpprinter
4. 重编[失败]：添加debug选项和修改，删除tIC和icecream
5. 重编[失败]：只保留DEBUG选项，代码都不修改。
6. 重编[成功]：回退到git HEAD~
7. 总结：测试确实debug选项的原因。
在感兴趣的新地方插入cpprinter，来理解代码逻辑，寻找入口。
1. 在op_api add插入cpprinter, 并跑完一轮，来确定使用了哪些线程

[x] PTA使用export DEBUG=1开启debug模式，在OpenSora样例下会报错result.use_count() <= 1

这是torch会校验DEBUG情况，但是PTA的值为2。为此需要修改torch包，删除gen_variable_type.py的对应行

if ( xxx not in DONT_ENFORCE_STORAGE_IMPL_xxx):
    stmts_after_call += []

240924¶

上午

T1/2/3/4: 分析OpenSora失效点，二分法测试多种情况
T5: 分析清楚当前的数据，测试下一步：在op_api add插入cpprinter, 并跑完一轮，来确定使用了哪些线程
1. 如猜想一样，就是主线程和反向线程。
T6: 后续修改策略：其实都不用看代码，在设置好数据和模型后，执行模型，会利用torch里注册的PTA的算子来执行。至于训练或者推理的入口，肯定是在pytorch端，PTA只是被动被调用下发算子，
1. 显示打印，setAffi的结果。
2. 策略，一开始赋值对应NPU的全部(除开前向和反向的两个)，后面单独设置前向和反向

当前策略：/tmp/cpp_595414

使用SetThreadName给已知的几种PTA线程重命名：

初始PTA NpuSysCtrl::Initialize，也是先大量调用opt add的线程
PTA Consume线程
PTA Release线程
PTA hcclCommWatchdog 或者 ProcessGroupHCCL
PTA NPUGuardImpl 线程，然后后少量调用opt add的线程，然后中断了。
PTA NpuSysCtrl::ExchangeDevice ????

SetThreadAffinity使用位置：

在SetDevice函数里，许多线程会执行多次，但是基本一次后会跳过
opt add开始

线程的执行顺序：根据打印的时间，给线程顺序排序, 明晰执行流程

51:58[Thread 1] ， NpuSysCtrl::Initialize —— setName & setAffi
52:49[Thread 4]: hcclCommWatchdog setName
52:49[Thread 2]: Consume setName
52:50[Thread 3]: Release setName
53:03[Thread 2]: Consume setAffi
53:03[Thread 3]: Release setAffi
54:15[Thread 6]: NpuSysCtrl::ExchangeDevice setAffi
54:31[Thread 1]-56:50, op_api::add {重复1075次，前向}
56:50[Thread 5]: NPUGuardImpl setAffi
56:53[Thread 5]-56:59, op_api::add {重复32次，前向}
56:59[Thread 4]: hcclCommWatchdog setAffi

time	Thread 1	Thread 2	Thread 3	Thread 4	Thread 5	Thread 6
51:58	NSysCtrl::Init setName&Affi
52:49		Cons setName		hcclC setName
52:50			Rel setName
53:03		Cons setAffi	Rel setAffi
54:15						NSysCtrl::ExchangeDevice setAffi
54:31	op_api::add
56:50					NGuardI setAffi
56:53					op_api::add
56:59				hcclC setAffi

现在看上去 Thread 1 也就是主线程就是前向，Thread 5就是反向线程。还有待全流程测试验证猜想。
如果上面正确，那么反向线程很好设置，NGuardI setAffi的位置基本就是反向开始的位置。

下午

T1/2/3/4: 思考&编码
T5: 重编, 任务排队
T6: 客户需求，编码添加自定义的绑定设置。

晚上

T1: 测试获得3%的收益，OpenSora 1p测试前向 0.385s -> 0.375s
1. 发现至少还有两个线程在工作，
2. 测试llama情况
编码
1. 由于其余的线程占用还比较高，将已知的NSysCtrl::ExchangeDevice绑核测试
2. 编码8p和非device 0的情况，

困难：测试需要排队，一等就是半个小时

整个项目编译耗时在12分钟左右, 修改其中一个文件或者一个文件夹的文件，由于变量名称打错和忘记写；编译了很久才报错，导致需要重新编译，能不能有快速测试当前cpp文件是否有语法错误的命令
- push之前测试基本语法错误g++ -fsyntax-only your_file.cpp
测试耗时长：运行一次OpenSora的1p在10mins，但是至少要运行三次取平均，至少要半小时。

达成阶段目标

尝试进一步理解线程设计
确定设置亲和性的策略
- 不要过早，避免并行读数据缓慢，在前向计算开始前，将hot线程绑单核
- 理想情况：找到入口，初始化函数
- trick，在NGuardI setAffi的位置根据
- ~~次一级在，算子的codegen位置都生成执行一次的亲和性设置~~
- ~~再次一级：第一个算子(add)执行一次，后续step都可以用。~~

To do

由于其余的线程占用还比较高，将已知的NSysCtrl::ExchangeDevice绑核测试，可以通过SetTAffi(coreIDRange, thread.self())快速测试。
测试llama情况
测试8p
测试非device 0情况

240925¶

上午

T1：8:50 机器8p都被占用了; 重新编译昨天修改好的
T2: 学习bash的函数传参
T3&4: 编写bash脚本，调试8p例子
T5: 问题：8p情况下htop感觉绑定到同一个核上了，需要仔细看一看

下午:

T1, env=1时程序有bug，会中断；同时需要答应8p的绑核信息。
T2, 修复环境变量为空时的bug
T3&T4: 修复逻辑，重新编译，中途别人任务占用，宕机，卡死频繁。
T5: 重新编译和修复bug

困难：编译，测试，排队耗时长

整个项目编译耗时在12分钟左右, 修改其中一个文件或者一个文件夹的文件，由于变量名称打错和忘记写；编译了很久才报错，导致需要重新编译，能不能有快速测试当前cpp文件是否有语法错误的命令
- push之前测试基本语法错误g++ -fsyntax-only your_file.cpp
测试耗时长：运行一次OpenSora的1p在10mins，但是至少要运行三次取平均，至少要半小时。
- 可视化了结果后，发现step在20步之后就比较稳定了，将原本脚本里的计算周期从200变成25，平均后15次

达成阶段目标

修改并编写了支持多NPU设备的代码，并完善了边界条件，正在编译，待测试。

To do

由于其余的线程占用还比较高，将已知的NSysCtrl::ExchangeDevice绑核测试，可以通过SetTAffi(coreIDRange, thread.self())快速测试。
测试
llama情况
测试8p
测试非device 0情况
测试组合，怡文说一个主任务多线程怎么样。
潜在客户场景：device 0不默认插在numa 0的情况。虽然实际生成有这个问题，但是怡文问了没有开发对应的C++接口，可能要自己写。
新问题：创建的8个线程好像一开始都是device 0，能不能通过什么环境变量来区别device id。
1. 有时：导致hccl初始化失败。
2. 导致8p的数据都绑定的和1p一样, htop看npu-smi的pid的a选项能看出都绑定的cpu 0
3. 疑问：那怡文的配置应该也有一样的问题，

240926¶

上午

T1: 问题：多NPU时无法实现分区，
1. 首先测试了怡文原本的配置，发现能正常分区，说明之前的SetAffi能有效利用device_id来分区。
2. 是static修饰变量初始化的原因。
T2: 问题：删除了怡文static const竟然导致了seg fault
T3&4: OpenSora 8p * 2 测试
T5&6: 看如何测试llama，和脚本？

下午

T1: llama脚本通过修改conda的transform包来计时
T2：测试发现demo_ll.py在千次循环时，会劣化 48ms->58ms, 不清楚是我的问题（git 8f3714），还是v2.1.0本身的问题。
T3: 代码回退到修改前，测试初始基准。是v2.1.0本身的问题，确实会劣化;
T4&T5: 测试了每日包，也存在劣化的问题。
T6: 版本转测让路

问题现象：llama程序在多step的迭代时，会在400步后性能会劣化20%

后续实验发现：

如果只是重复实验，劣化的步数是固定的第432步，不会变化。
问题是早已存在的，不是我的新代码引入的：对于PTA的包无论是官方gitee的包，还是每日包。都存在这个问题现象。
如果更改TQ的环境变量1-> 2或者3，劣化的step数会延迟到1900步左右，但是劣化现象还是存在。

当前的结论：

暂时无法确定是哪里的问题，pytorch，PTA，还是机器硬件、OS调度的问题。

怡文：

transform/generate/utils.py

model_inputs = self.prepare_inputs_for_generation(input_ids, **model_kwargs)

需要前提移动到循环外，不然每次迭代input_ids会变大。

晚上

T1&2 实验 llama多step劣化的原因
T3&T4 程序会在432步时，突然变慢 47->57ms

240927¶

上午：

T1&2&3&4&5 继续测试和可视化数据，观察劣化原因
1. 发现TASK_QUEUE_ENABLE=2/3 会延迟劣化到1900步左右
2. TODO：400步的时候save，然后重新跑，来区分是运行环境还是数据的原因
T6 OpenSora数据可视化，数据十分稳定，不会像llama那样波动
1. pgo二次编译就是先编译执行一次，获取指令执行信息（分支路径），来指导第二次编译

下午

T1-5：Ascend质量誓师大会：硬件、HDK、CANN、MindIE(新推理)、文档维护都问题多多，尤其是硬件质量导致很多集群问题，软件问题注意集中在：
1. 没有考虑到用户的可能情况：墨菲定律，又译为摩菲定律，原句是：如果有多种方式去做某事，而其中一种方式将导致灾难，则必定有人会这样选择。在科学和算法方面与英文所谓的“worst-case scenario”
2. 错误码缺失，定位不明。
3. 软件问题难以定位
T6：llama的demo_ll.py在修改成npu:1时，性能劣化严重, 开启TQ2，代码是默认v2.1.0
1. npu0 34ms, + taskset 0-23 31ms
2. npu1 45ms, + env 1 严重劣化到 140ms；观察htop发现，主线程在numa0，但是其余PTA辅助线程在numa1；猜测主线程numa不对是主要原因；潜在危险：这个特性应该被我继承了。
3. 需要测试我的修改
好多人用，今天又是严重排队的一天。
能不能写成内部文档，外部的能写的太少了。
1. 原本以为可以用draft来实现公开和私有的隔离，但是mkdocs不支持，
2. docuwiki的方法也不行，服务器的网络限制上传
3. 首先需要测试华为的服务器能不能正常搭建内部网页, 我原本以为想2012一样，能轻易实现。绿区服务器是不行的，搭建了本地电脑也访问不了。

llama的demo_ll.py在修改成npu:1时，性能劣化严重。

这是llama内部识别卡的问题，可以通过环境变量export ASCEND_RT_VISIBLE_DEVICES=1,来把1卡当作0卡。

240929¶

上午

T1&T2: 排队，我真是急死了，测试不了，怎么改啊。
1. 服务器上搭建网站也不行。
T3&4&5: 总结思路，统计数据，重新补测。

下午

T1-5: 编译安装torch，来支持PTA的DEBUG模式。来熟悉简单add算子的dispatch流程。
T6-8: undefined symbol 也是之前cpprinter遇到的问题，编译环境竟然不同。导致多了c++11的选项。

240930¶

上午

T1-3: 确定是ABI不匹配的问题，尝试出编译的顺序逻辑：两个都先编译好才能安装
T4: 排队, 顺利GDB，但是超级缓慢，半小时才启动的那种。

241008¶

导师说，环境变量设置参考之前的。
并且绑核要Ascend_logd记录，通过 export ASCEND_GLOBAL_LOG_LEVEL=0开启，同时设置export ASCEND_PROCESS_LOG_PATH=$HOME/log/
安全设置，先是粗粒度NUMA绑

241012¶

上午

T1-3: 后续要求开发。编写了策略

下午

代码去除cout cerror，换成官方的LOG
根据新的环境变量格式来修改代码。
和导师汇报了劣化的可能，并重新测量了OpenSora 的时间，
1. 整体env2: 258, env1：233， env0: 253
2. 35steps: env2: 258, env1：233， env0: 253
问题：
1. env0 也使用了env2
2. 为什么训练step加速了，但是总时间劣化了。可以考虑训练前后使用api启动 1. 程序的函数栈相当的厚重：aclLOG：debug模式下，OpenSora总时间819，中间python从执行第一条指令到结束726s，py后还需要32s，py前需要31s
3. 能不能加速编译，只变异修改的.o和最后的.so。是不是只要make就行。

241013¶

下午

打印输出，分析env0错误原因：简化了脚步，重新编译了 1. 新问题：OpenSora找不到log，需要从简单例子开始验证。 2. 原因：是LOG，默认有覆盖功能，最多生成10个20MB的文件，老的会被删除。可以通过变量DeviceMaxFileNum控制，但是还是建议从简单的开始。 2. 还有个warning写成debug了 3. 打印函数有错误, 原因是string.c_str() 4. 快速编译 make torch_npu/fast

241014¶

上午

T1-3：阅读3ms的团队文档
T4-5: 分析昨晚数据
1. env2 平均 253，env2 隔离核平均256，env1 劣化严重 493，env0 稳定 238
2. 问题一：env1 劣化严重。原因是之前留下的MAP接口有其他的作用，导致限制了
3. 分析step前后时间，前后确实有些许劣化 1. env2 253 = 31 + 180 + 43 (不可信) 2. env1 493 = 33 + 418 + 42 (不可信) 3. env0 233 = 19 + 191 + 23
4. 问题二：env2的区间不是[],需要重测。

下午

T1: 重新测试数据，可信

1. env2 258 = 30 + 181 + 46 （default 主线程绑1，其余0-23）
    1. 258 = 32 + 186 + 39 （default 主线程绑1，其余5-23）
    2. 247 = 32 + 176 + 38 （default 主线程绑1，其余5-23）
    3. 233 = 30 + 183 + 19 （default 主线程绑0-23，其余0-23，PTA的余下1对1）
    4. 233 = 30 + 178 + 25 （default 主线程绑0-23，其余0-23，PTA的余下1对1）
    5. 238 = 28 + 184 + 26 （default 主线程绑0-23，其余0-23，PTA的余下1对1）
2. env1 233 = 29 + 174 + 29
    1.  (233 = 29 + 181 + 22)
    2.  (238 = 32 + 184 + 22)
3. env0 248 = 18 + 201.47 + 29

前后劣化

env1的平均使得数据并行18s -> 29s ,启动慢了10s
主线程绑1 在step确实有提升，但是收尾会变慢由25s ->35s 甚至40s。

py前应该是import内容的构造/init, 确实在torchrun 8p时，会受到线程conf影响env1或者2的影响， 1. 具体来说是from colossalai import booster，最终调用了torch_npu._C._npu_init, 在8p时，粗或者细粒度绑核，会导致初始化边长7.8s->19.8s py后是对象的析构

实验自动化程度太低

实验分成两部分：

最快速的、全功能例子，来验证程序的正确性(Info,Debug输出符合预期)
批量的实验，验证稳定性和性能：
一种是将时间打印在log文件里(不要打屏)，然后程序外处理log数据到Excel规整。避免了程序内数据处理，但是需要程序外规整，尤其是多线程输出混杂的情况。 1. 注意数据要可计算，并且可读取(不要和括号连接在一起)
一种是程序内格式化数据直接输出到Excel文件（环境变量），但对性能有些许损耗，优先关键点。

241015¶

上午T1-4: 编写自动化时间线脚本，等机器
下午转测完，环境/驱动变了，hccl初始化报错
晚上跑了
PPT：PyTorch主线程(PTA主线程)、二级流水线程、数据加载进程。
晶博的问题：数据加载不是线程是进程，然后变慢的到底是什么操作启动了线程，不要从实验结果解释。

241016¶

上午：开了一上午的24Q4展望
下午：支持华为云项目对齐，编写文档，编写定时脚本。

241017¶

上午：计划实现怡文说的暴露接口还原，和环境变量统一格式，
1. 没机器待测试
下午：测试了，错误还是有但是不是我的问题:env0也有
1. 完成了子线程、进程、multiprocessing的测试
晚上：时间过长：
1. py前应该是import内容的构造/init, 确实在torchrun 8p时，会受到线程conf影响env1或者2的影响， 1. 具体来说是from colossalai import booster，最终调用了torch_npu._C._npu_init, 在8p时，粗或者细粒度绑核，会导致初始化边长7.8s->19.8s
2. py后是对象的析构
TODO：
1. 稍微看下init代码（C++ Profile）
2. 切分训练前时间，特别是dataloader和torch_npu的初始化（viztracer in detail，env选项对dataloader影响甚微）
3. 将setAffinity从setDevice里移出来，绑在setName的PTA线程相关的地方。以最小对py前后的影响。

241018¶

crontab没触发？等机器，分析尾部的时间, 猜测是atexit挂载的钩子的torch_npu._C._npu_shutdown，说明不是的
1. 实验 env2 torch_npu._C._npu_shutdown 7.6s ，尾部共 42s (没开启了reset_threads_affinity)
2. 实验 env2 torch_npu._C._npu_shutdown 12.5s ，尾部共 48s (没开启了reset_threads_affinity)
3. 实验 env2 torch_npu._C._npu_shutdown 12.9s ，尾部共 29s (开启了reset_threads_affinity)
4. 实验 env0 torch_npu._C._npu_shutdown 7.9s ，尾部共 26s
5. 说明不是的，但是说明reset_threads_affinity还是有效的。
尾部通过monkey patching拦截
1. env2 结尾48s = 20s + atexit(12s + 6s同步波动) + 10s (没开启了reset_threads_affinity)
2. env2 结尾26s = 5s + atexit(8s + 1s同步波动) + 11s (开启了reset_threads_affinity)
3. env0 结尾31s = 5s + atexit(12s + 4s同步波动) + 10s
4. env0 结尾22s = 4s + atexit(7s + 4s同步波动) + 7s
5. 说明reset_threads_affinity还是有效的, 并且生效的区域是atexit前的地方。
TODO：
1. C++ Profile torch_npu._C._npu_init
2. 将setAffinity从setDevice里移出来，绑在setName的PTA线程相关的地方。以最小对py前后的影响。

241021¶

之前代码思路：torch控制的线程，利用了setDevice的接口，在HOST进程与NPU设备绑定的时候设置亲和性。
1. 值得注意的是，这只会触发一次，虽然触发位置多(e.g.,RegisterNPU::wrapper_npu_empty_strided())，但是会static thread_local int local_device==device，然后跳过。
2. 思路是很巧妙的，因为这将torch上层的线程创建时设置亲和性(PTA感知不到)，变成了每个线程(利用thread_local)初次设置/变设备(静态变量来保证一次)时设置亲和性
反向算子新线程的逻辑是：torch为反向算子创建了新线程(暂时代码不明)到新设备上，这个线程要处理很多算子，第一个算子触发通过了setDevice, 并且是新线程，所有设置新的亲和性。
主线程一开始init会SetDevice，后面算子也会调用SetDevice，只不过被跳过了。但是之前的SetName生效了，所以导致所有线程被设置为NPUGaurd的名字。
重构动机：绑核导致，init变慢了，具体原因？？？
重构思路：将setAffinity从setDevice里移出来，来跳过init时触发的SetDevice。但是你就找不到算子下发的时机了。
1. 另一种思路，一开始设置全部就行，虽然不影响dataloader，但是运行时怎么隔离？
需要研究的，
1. c10_npu与PyTorch的c10的DeviceGuard实现强相关，需要看torch代码
要做PPT了！！！（做了一晚上）

241022¶

epoch间的dataloader时间没有统计，分析dataloader的调用栈
写PPT
实验：
1. epoch里的dataloader从第二次开始需要并行，1p会从2s劣化到8s
2. 8p总时间变长了，原因是第一步的backward极具劣化，15s->35s。这是新修改引入的。
  1. 难道是这时候亲和性设置，导致数据移动。
需要看vizTracer堆栈，dataloader，backward
1. 严格监控侵入式修改处的执行情况(调用次数，时机，时间 - cpprinter), 不打印栈，太耗时了.
晚上：研究bash python cmake profile策略

241023¶

ninja用不了，ccache用上，cPython 显示98时间还是submodule调用(其中有个generate_code占用了大部分时间68%)
测量yiwen的编译选项-fstack-protector-strong和-fstack-protector-all的区别
当前担心点：
1. 初始化变慢，新写法解决了初始化，但是第一次step fallback慢了10s 1. 需要分析堆栈 2. 本身env0就慢，先不管
2. step里的dataloader时间没有统计进去，感觉时间出问题了 1. 重点，python侧profile：epoch0 初始化，epoch1 就开始fork和join了，重点在于进程阻塞在一个核 1. C++侧，dataloader调用了PTA的什么呢？ 2. 预估方案，在dataloader和save前，reset_threads
3. 训练后线程恢复实现了接口torch_npu._C._reset_threads_affinity()，但是不是好方法.
4. 提升没有那么大，波动却十分大，加上没机器，和别人干扰。难以判断各种代码和配置的优劣。

241027¶

之前几天中期答辩PPT重做，详设文档，民主生活会
周日加班：cpprinter完成预期的功能，和PTA结合良好。
问题：dataloader迭代结束后，为什么重新init了。
批量实验探究一个问题: 虽然按照时间隔离里，那之前的空间隔离还有用吗，应该是有用的 unknown 5-24。隔离了其余的操作。
实验结果：在重构的代码下，下发阶段主线程绑单核是肯定的正收益；值得探究的是下发阶段unknown隔离的效果
1. 隔离了，下发计时是变快了一点，但是 step 0 的backward貌似一定会慢10s（稳定性有待测量），导致总时间会略有劣化，
2. 有待大量实验确认
3. 难以解释。

241028¶

整理了实验数据：unknown隔离在下发阶段平均提升 0.16%，属实有点小，端到端还下降 1%。就不修改了。
先统一环境变量解析，验证正确性。
1. 再分支出v2.1.0_synrecoder合并yiwen的commit，
2. 再测试mf的环境。
流水线测试：申请权限，加__init__.py里修改环境变量打包。
TMG的PPT，先给晶博看，再参会。

241029¶

上午
1. T1-T3: 测试了自定义选项的异常值，通过。
todo
1. 再分支出v2.1.0_synrecoder合并yiwen的commit，
2. 再测试mf的环境。
3. cman L2 缓存编译
4. 自验实验报告(四个模型) + 完善设计文档，归档设计文档。
5. 流水线测试：申请权限，加__init__.py里修改环境变量打包, 冒烟自测。通过
6. BCG协议签署 + 还机器
7. 出差房租等申请

241030¶

上午： L2数据预取cman，读代码编译，发现系统内核不支持。
下午：
1. mf环境熟悉， 1. kQueueCapacity变大，同步时间变长，下发变快了。 2. 测试两个小模型 3. 安排四个模型的运行
2. 预取寻优

241031¶

紧急：
1. 实验结果：OpenSora1.1 不达预期， llama没实现细粒度绑核。
2. 改进： llama需要重新profile寻找， 1. [x] acl_thread启动的时候，已经到新设备了，这里setMainThread
3. OpenSora1.1 不达预期： 1. [x] jinbo说，dataloader一直会运行。 unknown设置5-23，先尝试隔离：
4. 发现小问题：一开始主线程都是在NUMA1 上，后来都切换了。 1. [x] 但是acl_thread启动的时候，已经到新设备了，这里setMainThread。
5. 怡文分支领先许多，要么同步，要么重新和自己对比 1. [x] 把py里的环境变量控制去掉。
下午：
1. 根因是mf的脚本一层套一层，在最里面固定是粗粒度绑核了。
2. 实现了上面的修改，提升在7%左右。
TO DO
1. 出差房租等申请
2. 自验实验报告(四个模型)+ 完善设计文档，归档设计文档。
3. 同步主仓，并且cherry-pick到v2.1.0, pull 主仓， reset到主仓，然后push， 1. [ ] 最后PR
4. L2 分区和预取寻优。
5. 910C的效果。晚上测试

241101¶

OpenSora 1.2 不及预期，check过了，算子下发时各个核心正常绑定了，
1. 测了两对数据，时间产生了env1 < env2 < env1 < env2 的顺序。
2. 变成前19step 测试
安装和测试49 的910C的环境，并定时。

241102¶

ip 49 的910C在与mf的基准对比的情况下，效果确实不错
1. 910C的env1 的llama基准测试，自测env1是24左右。
184的OS2还是不达预期
1. env2 和 1 step19 129 要批量测试一次。 1. [x] step129 确信是没提升，甚至劣化1%。 2. [ ] step19 env1 更快了。先确定step
2. 晶博的意见：测试第二层循环间的数据处理时间？ 1. [x] 阅读MM代码 2. [ ] 复制一份，然后viztracer内容-> 判断mf划的范围是不是大了。 3. [ ] yiwen同步的原理： 1. [ ] 好奇怪，通信时间为什么这么上下变化？
3. 预期是E2E有收益，sync时间是大致不变的(但是绑核会不会变近，然后变小)。
TO DO
1. 出差房租等申请
2. 自验实验报告(四个模型)+ 完善设计文档，归档设计文档。
  1. 还有llama 3完全没测试。mf说很快。
3. 同步主仓，并且cherry-pick到v2.1.0, pull 主仓， reset到主仓，然后push， 1. [ ] 最后PR
4. L2 分区和预取寻优。
5. 出支持包3.10

241104¶

上午拍昇腾宣传短片，当背景板
1. L2 Partition
下午：L2 Partition，尝试了多种策略，最好的策略提升6%。
todo
1. llama 3测试
2. 184劣化测试

241105¶

llama 3 确实有劣化，理解了同步的时间计算
由于难以解释劣化，并且llama3 跑的不慢，启用原本的MAP变量来调试DEBUG
1. 发现unknown绑全核就没问题了，
2. 难以解释
920C的绑核虽然没有劣化，但是有隐藏问题：
1. 开了多线程，NUMA的划分变了。
2. 920C的卡是8卡16chip，torch_run 看npu-smi会使用前7个chip

241106¶

等PR的CI，合入代码
UT 2.5 失败4次，代码监视打回三次。
184的劣化问题，貌似不严重了。发现OS的优化没有还原。

241007¶

合入5分支，发转测邮件。
重新测量184的llama3基准
下午拍戏，科目一准备。

环境变量文档¶

`CPU_AFFINITY_CONF` 使用说明¶

功能描述：¶

在 PyTorch 训练或在线推理场景下，可以通过此环境变量控制 CPU 端算子线程的处理器亲和性（即线程绑核）。该配置能够优化线程的执行效率，避免跨 NUMA（非统一内存访问架构）节点的内存访问，减少线程调度开销。

可选参数：¶

mode:<value> 绑核模式，取值如下：
- 1：将进程下的所有线程绑定在 NPU 对应的 NUMA 节点的 CPU 核组上，避免跨 NUMA 节点的内存访问。
- 2：在 mode:1 的基础上进一步优化, 将进程中的主要线程锚定在 NUMA 节点的某颗固定核心上，减少线程在同一NUMA节点内不同CPU。
- 其他值表示不启用绑核功能（默认不开启）。
npu<value>:<value>-<value> 自定义 NPU 的绑核范围：
- 例如，npu0:0-2 表示运行在编号为 0 的 NPU 上的进程会绑定到编号为 0、1、2 的 CPU 核心。
- 默认情况下，mode 参数为 1 时此设置生效，并可用于覆写 mode:1 时的绑核策略。比如有两张卡 npu0 和 npu1，对于设置 export CPU_AFFINITY_CONF=mode:1,npu0:0-1，npu0 的绑核策略会被覆写，而 npu1 则保持 mode:1 的默认绑核策略。

参数配置格式：¶

CPU_AFFINITY_CONF=<option1>:<value1>,<option2>:<value2>

说明：¶

NUMA 节点对应的 CPU 核组可以通过命令 lscpu 查看。
默认情况下，npu0 或 Device 0 对应的核组是 NUMA0。

配置示例：¶

示例一： 将所有线程绑定到 NPU 对应的 NUMA 节点：
```
export CPU_AFFINITY_CONF=mode:1
```
示例二： 将主要线程固定在指定的 CPU 核心上：
```
export CPU_AFFINITY_CONF=mode:2
```

示例三： 自定义多张 NPU 卡的绑核范围：

export CPU_AFFINITY_CONF=mode:1,npu0:0-1,npu1:2-5,npu3:6-6

DEBUG¶

感兴趣的地方打断点，观察触发时机，频率，函数栈，
通过info threads命令查看所有线程的状态，并使用thread <thread_id>切换到特定线程进行调试。

// 程序的执行逻辑： 初始化，算子下发，复原
第一次setAffinity
at::Tensor add()
// 线程创建的地方, 是哪个线程(主线程)创建的，何时创建的
void Repository::InitRepo(c10::DeviceIndex device_id) {
void ReleaseQueue::InitReleaseQueue(c10::DeviceIndex device_id) {
hcclCommWatchdogThread_ = std::thread(&ProcessGroupHCCL::hcclCommWatchdog, this); 
// 未知的线程
PyObject* THNPModule_setDevice_wrap(PyObject* self, PyObject* arg)
// 代码里Tensorpipe使用了相当多线程。用于进程间通信的传递。很有可能就是热点线程。
handelCopyRequests

add 算子的调用栈，走了路径五(详见24Q4P2)

wrapper_NPU_Tensor_add之上就是torch的逻辑。但是#1和#2也是codegen自动生成的。

#0  op_api::add (self=..., other=..., alpha=...) at /root/document/shaojie/github/pytorch/third_party/op-plugin/op_plugin/ops/opapi/AddKernelNpuOpApi.cpp:79
#1  0x0000ffff07596250 in op_plugin::add (self=..., other=..., alpha=...) at /root/document/shaojie/github/pytorch/third_party/op-plugin/op_plugin/OpInterface.cpp:4082
#2  0x0000ffff05bf00fc in at::(anonymous namespace)::(anonymous namespace)::wrapper_NPU_Tensor_add (self=..., other=..., alpha=...) at /root/document/shaojie/github/pytorch/torch_npu/csrc/aten/RegisterNPU.cpp:378
#3  0x0000ffff05dbd42c in c10::impl::detail::WrapFunctionIntoFunctor_<c10::CompileTimeFunctionPointer<at::Tensor(const at::Tensor&, const at::Tensor&, const c10::Scalar&), at::(anonymous namespace)::(anonymous namespace)::wrapper_NPU_Tensor_add>, at::Tensor, c10::guts::typelist::typelist<const at::Tensor&, const at::Tensor&, const c10::Scalar&> >::operator() (args#2=..., args#1=..., args#0=..., this=0x7768030) at /home/anaconda3/envs/t00906153_bindCore/lib/python3.8/site-packages/torch/include/ATen/core/boxing/impl/WrapFunctionIntoFunctor.h:13
#4  c10::impl::wrap_kernel_functor_unboxed_
        <
            c10::impl::detail::WrapFunctionIntoFunctor_
            <
            c10::CompileTimeFunctionPointer<at::Tensor(const at::Tensor&, const at::Tensor&, const c10::Scalar&), at::(anonymous namespace)::(anonymous namespace)::wrapper_NPU_Tensor_add>, 
            at::Tensor,
            c10::guts::typelist::typelist<const at::Tensor&, const at::Tensor&, const c10::Scalar&>
            >, 
            at::Tensor(const at::Tensor&, const at::Tensor&, const c10::Scalar&)
        >
::call(c10::OperatorKernel *, c10::DispatchKeySet, const at::Tensor &, const at::Tensor &, const c10::Scalar &) 
(functor=0x7768030, args#0=..., args#1=..., args#2=...)
    at /home/anaconda3/envs/t00906153_bindCore/lib/python3.8/site-packages/torch/include/ATen/core/boxing/impl/make_boxed_from_unboxed_functor.h:464
#5  0x0000ffffb286beb0 in c10::callUnboxedKernelFunction<at::Tensor, at::Tensor const&, at::Tensor const&, c10::Scalar const&> (
    unboxed_kernel_func=0xffff05dbd374 <c10::impl::wrap_kernel_functor_unboxed_<c10::impl::detail::WrapFunctionIntoFunctor_<c10::CompileTimeFunctionPointer<at::Tensor(const at::Tensor&, const at::Tensor&, const c10::Scalar&), at::(anonymous namespace)::(anonymous namespace)::wrapper_NPU_Tensor_add>, at::Tensor, c10::guts::typelist::typelist<const at::Tensor&, const at::Tensor&, const c10::Scalar&> >, at::Tensor(const at::Tensor&, const at::Tensor&, const c10::Scalar&)>::call(c10::OperatorKernel *, c10::DispatchKeySet, const at::Tensor &, const at::Tensor &, const c10::Scalar &)>, functor=0x7768030, dispatchKeySet=...) at ../aten/src/ATen/core/boxing/KernelFunction_impl.h:50
#6  0x0000ffffb2776df4 in c10::KernelFunction::call<at::Tensor, at::Tensor const&, at::Tensor const&, c10::Scalar const&> (dispatchKeySet=..., opHandle=..., this=0x9cded0) at ../aten/src/ATen/core/boxing/KernelFunction_impl.h:103
#7  c10::Dispatcher::redispatch<at::Tensor, at::Tensor const&, at::Tensor const&, c10::Scalar const&>(c10::TypedOperatorHandle<at::Tensor (at::Tensor const&, at::Tensor const&, c10::Scalar const&)> const&, c10::DispatchKeySet, at::Tensor const&, at::Tensor const&, c10::Scalar
const&) const (this=0xffffbb7847b8 <c10::Dispatcher::realSingleton()::_singleton>, op=..., currentDispatchKeySet=...) at ../aten/src/ATen/core/dispatch/Dispatcher.h:674
#8  0x0000ffffb2bc0cd8 in c10::TypedOperatorHandle<at::Tensor (at::Tensor const&, at::Tensor const&, c10::Scalar const&)>::redispatch(c10::DispatchKeySet, at::Tensor const&, at::Tensor const&, c10::Scalar const&) const (args#2=..., args#1=..., args#0=...,
    currentDispatchKeySet=..., this=<optimized out>) at ../aten/src/ATen/core/dispatch/Dispatcher.h:510
#9  at::_ops::add_Tensor::redispatch (dispatchKeySet=..., self=..., other=..., alpha=...) at aten/src/ATen/Operators_2.cpp:1007
#10 0x0000ffffb52c4010 in at::redispatch::add (dispatchKeySet=..., self=..., other=..., alpha=...) at aten/src/ATen/RedispatchFunctions.h:597
#11 0x0000ffffb51b9cc4 in torch::autograd::VariableType::(anonymous namespace)::<lambda()>::operator()(void) const (__closure=0xffffffffda28) at ../torch/csrc/autograd/generated/VariableType_2.cpp:5696
#12 0x0000ffffb51ba0c8 in torch::autograd::VariableType::(anonymous namespace)::add_Tensor (ks=..., self=..., other=..., alpha=...) at ../torch/csrc/autograd/generated/VariableType_2.cpp:5697
#13 0x0000ffffb528faa0 in c10::impl::detail::WrapFunctionIntoFunctor_<c10::CompileTimeFunctionPointer<at::Tensor(c10::DispatchKeySet, const at::Tensor&, const at::Tensor&, const c10::Scalar&), torch::autograd::VariableType::(anonymous namespace)::add_Tensor>, at::Tensor, c10::guts::typelist::typelist<c10::DispatchKeySet, const at::Tensor&, const at::Tensor&, const c10::Scalar&> >::operator() (args#3=..., args#2=..., args#1=..., args#0=..., this=0x269a9a0) at ../aten/src/ATen/core/boxing/impl/WrapFunctionIntoFunctor.h:13
#14 c10::impl::wrap_kernel_functor_unboxed_<c10::impl::detail::WrapFunctionIntoFunctor_<c10::CompileTimeFunctionPointer<at::Tensor(c10::DispatchKeySet, const at::Tensor&, const at::Tensor&, const c10::Scalar&), torch::autograd::VariableType::(anonymous namespace)::add_Tensor>, at::Tensor, c10::guts::typelist::typelist<c10::DispatchKeySet, const at::Tensor&, const at::Tensor&, const c10::Scalar&> >, at::Tensor(c10::DispatchKeySet, const at::Tensor&, const at::Tensor&, const c10::Scalar&)>::call(c10::OperatorKernel *, c10::DispatchKeySet, const at::Tensor &, const at::Tensor &, const c10::Scalar &) (functor=0x269a9a0, dispatchKeySet=..., args#0=..., args#1=..., args#2=...) at ../aten/src/ATen/core/boxing/impl/make_boxed_from_unboxed_functor.h:481
#15 0x0000ffffb286beb0 in c10::callUnboxedKernelFunction<at::Tensor, at::Tensor const&, at::Tensor const&, c10::Scalar const&> (
    unboxed_kernel_func=0xffffb528f9e0 <c10::impl::wrap_kernel_functor_unboxed_<c10::impl::detail::WrapFunctionIntoFunctor_<c10::CompileTimeFunctionPointer<at::Tensor(c10::DispatchKeySet, const at::Tensor&, const at::Tensor&, const c10::Scalar&), torch::autograd::VariableType::(anonymous namespace)::add_Tensor>, at::Tensor, c10::guts::typelist::typelist<c10::DispatchKeySet, const at::Tensor&, const at::Tensor&, const c10::Scalar&> >, at::Tensor(c10::DispatchKeySet, const at::Tensor&, const at::Tensor&, const c10::Scalar&)>::call(c10::OperatorKernel *, c10::DispatchKeySet, const at::Tensor &, const at::Tensor &, const c10::Scalar &)>, functor=0x269a9a0, dispatchKeySet=...) at ../aten/src/ATen/core/boxing/KernelFunction_impl.h:50
#16 0x0000ffffb2bc0aa0 in c10::KernelFunction::call<at::Tensor, at::Tensor const&, at::Tensor const&, c10::Scalar const&> (dispatchKeySet=..., opHandle=..., this=0x9ce8b0) at ../aten/src/ATen/core/boxing/KernelFunction_impl.h:103
#17 c10::Dispatcher::call<at::Tensor, at::Tensor const&, at::Tensor const&, c10::Scalar const&>(c10::TypedOperatorHandle<at::Tensor (at::Tensor const&, at::Tensor const&, c10::Scalar const&)> const&, at::Tensor const&, at::Tensor const&, c10::Scalar const&) const (op=...,
    this=0xffffbb7847b8 <c10::Dispatcher::realSingleton()::_singleton>) at ../aten/src/ATen/core/dispatch/Dispatcher.h:657
#18 c10::TypedOperatorHandle<at::Tensor (at::Tensor const&, at::Tensor const&, c10::Scalar const&)>::call(at::Tensor const&, at::Tensor const&, c10::Scalar const&) const (args#2=..., args#1=..., args#0=..., this=<optimized out>)
    at ../aten/src/ATen/core/dispatch/Dispatcher.h:505
#19 at::_ops::add_Tensor::call (self=..., other=..., alpha=...) at aten/src/ATen/Operators_2.cpp:1000
#20 0x0000ffffbc468740 in at::Tensor::add (this=0xffffffffe000, other=..., alpha=...) at aten/src/ATen/core/TensorBody.h:1658
#21 0x0000ffffbc570dc4 in torch::autograd::<lambda(const at::Tensor&, const at::Tensor&, const c10::Scalar&)>::operator()(const at::Tensor &, const at::Tensor &, const c10::Scalar &) const (__closure=0xffffffffdf20, self=..., other=..., alpha=...)
    at ../torch/csrc/autograd/generated/python_torch_functions_2.cpp:1385
#22 0x0000ffffbc571264 in torch::autograd::THPVariable_add (self_=0x0, args=0xffff80ee1780, kwargs=0x0) at ../torch/csrc/autograd/generated/python_torch_functions_2.cpp:1387
#23 0x0000000000443120 in cfunction_call_varargs ()
#24 0x00000000004437f0 in _PyObject_MakeTpCall ()

数据¶

llama 十组数据平均 49.7816 ms -> 49.3209 ms, 提升 0.9%
OpenSora 1p 三组平均前向部分算子下发提升 1.84%, E2E提升1.44%
OpenSora 8p 三组平均前向部分算子下发提升 1.53%, E2E提升3.16%

总结¶

目标与动机：通过细粒度绑核，使得算子下发线程能在最亲和的核上独占调度，一方面避免竞争，一方面避免OS线程切换导致的开销，使得算子下发的速度加快。
难点与发现：
- 理清楚pytorch和PTA的线程的工作情况，并找到并对目标线程进行设置。
- 经过实验发现，线程的亲和性设置是会被创建的子线程继承的：
  - 如果在不合适的地方(过早)对线程进行细粒度的亲和性设置，会对子线程也同样设置，产生非预期的影响。比如，导致父子线程竞争同一个核，导致性能大幅劣化。
- PTA下发前向算子的线程就是pytoch的主线程，如何在不修改torch代码的情况下设置pytoch的主线程的亲和性。
- 同时需要对线程实现及时复原，
理解与对策：
- 纳入考量的全部线程，除了PTA的线程，还包括pytorch的灵活调度的线程池。
- 目标线程确定为，主线程为前向算子下发线程，NPUGaurd线程为反向算子下发线程。
- 两阶段的线程设置：
  - 初始阶段为其余线程分配核：虽然不能修改torch代码，但是可以利用在初始化阶段torch对PTA的调用，将非目标线程绑定在其余核上。
  - 算子下发阶段再分配：观察到算子下发阶段会初始化NPUGuard，在此时刻重新分配目标线程的独占核。
负面：细粒度绑核需要额外计算和syscall，单次0.6s, 调用大约6~7次，增加耗时5s左右
潜在危险 - 难以复原环境：
- 由于结束训练，不再使用算子，在被调用的PTA侧是难以感知的，故难以找到时机复原线程的独占设置。
- 这导致在算子执行完之后，如果又进行数据读取之类调用torch线程池的操作，由于PTA在算子开始执行时绑定到一个核，如果主线程新创建子线程会导致无法并行读取数据。
潜在生成情况：device 0不默认插在numa 0的情况。

剩余目标

测试效果baichuan
进一步研究：由于其余的线程占用还比较高，比如已知的NSysCtrl::ExchangeDevice绑核测试
- API可以通过SetTAffi(coreIDRange, thread.self())快速测试。
- 但是SetDevice可能被多个线程不同时刻调用很多次了，需要理解线程，并找到这个线程的初始化或者其他特殊的入口。
研究遇到的非目标相关问题。
对代码的理解还是不够()
- 线程创建的具体行还没寻找
- python调用pytorch再调用PTA的代码栈还没打印过，没check过。

可视化和理解代码的手段

简单例子add 算子

C++侧使用GDB，
python侧打印调用栈viztracer
with torch_npu.profiler.profile() 可以看PTA里算子的使用情况。

算子下发优化¶

看了现有资料，有待对齐的点

有各算子下发的时间，但是总时间是多少，或者说占比有多少，这样才能计算可能收益？
1. 已有算子的总时间大约1031ms
2. 对应的前向总时间是408ms,
相关代码在哪里
1. 隶属新仓库 op-plugin
2. 命令空间相当多 op_plugin根据情况调用acl_op or op_api, 最终都调用 acl_op
3. excel里的npu只是怡文随手写的，

OS优化¶

机器在空载的时候，还有260GB的内存占用，是分配了大页内存
free -h 和 cat /proc/meminfo |grep huge 可以看见Hugetlb: 262144000 kB = 250GB

参考文献¶

怡文W3的博客
w3 & wiki

[DevLog]24Q3P1 - Optimize PTA With Thread Affinity

240923¶

240924¶

240925¶

240926¶

240927¶

240929¶

240930¶

241008¶

241012¶

241013¶

241014¶

241015¶

241016¶

241017¶

241018¶

241021¶

241022¶

241023¶

241027¶

241028¶

241029¶

241030¶

241031¶

241101¶

241102¶

241104¶

241105¶

241106¶

241007¶

环境变量文档¶

CPU_AFFINITY_CONF 使用说明¶

功能描述：¶

可选参数：¶

参数配置格式：¶

说明：¶

配置示例：¶

DEBUG¶

数据¶

总结¶

算子下发优化¶

OS优化¶

参考文献¶

评论

`CPU_AFFINITY_CONF` 使用说明¶