最近使用 Pytorch 进行模型训练时,模型在训练到一小部分后程序均被停止。第一次以为是由于机器上其他人的误操作,故而直接重新拉起训练。但第二次程序终止时,发现基本与第一次训练停止的训练 iteration 一致,故而尝试对问题进行定位。
问题描述
具体而言,在使用 Pytorch 训练时的错误信息类似如下所示:
File "/usr/lib/python3.7/runpy.py", line 193, in _run_module_as_main
"__main__", mod_spec)
File "/usr/lib/python3.7/runpy.py", line 85, in _run_code
exec(code, run_globals)
File "/usr/local/lib/python3.7/dist-packages/torch/distributed/launch.py", line 340, in <module>
main()
File "/usr/local/lib/python3.7/dist-packages/torch/distributed/launch.py", line 326, in main
sigkill_handler(signal.SIGTERM, None) # not coming back
File "/usr/local/lib/python3.7/dist-packages/torch/distributed/launch.py", line 301, in sigkill_handler
raise subprocess.CalledProcessError(returncode=last_return_code, cmd=cmd)
subprocess.CalledProcessError: Command '['/usr/bin/python3', '-u', xxx]' died with <Signals.SIGKILL: 9>.```
从中可以获得了信息是程序由于收到了对应的信号 SIGTERM,从而对应的信号处理 handler 被调用,最终使得程序运行的进程被终止。 SIGKILL 与 SIGTERM 均为传递终止信息的信号,也就是说有存在行为向运行中的程序发送了终止信号,所以问题在于定位发送信号的原因。
问题定位
首先由于输出显示程序收到了 SIGTERM 信号,所以尝试寻找发出对应信号的位置。由于发送信号的行为需要经过操作系统 kernel,这里可以通过 dmesg 命令查看最近的内核操作(实际是输出了内核中记录行为的 kernel ring buffer 的内容)来查看是否存在相关的信息。具体命令如下所示,其中 dmesg 的 -T 选项表示显示命令的操作时间。grep 的 -E 参数表示使用拓展的正则表达式进行匹配。 -i 参数表示忽略匹配的大小写问题,-B num 参数表示在匹配行之前另外输出 num 行的数据,主要可以用来看是否有上下文的相关信息。命令来自What killed my process and why?
dmesg -T | grep -E -i -B100 'killed process'
如在笔者机器上,出现的问题信息如下所示:
这里显示用户 uid = 1002 的进程由于 OOM 即 out of memory 的问题被 kill 了,且给出了在终止时整体的虚拟地址的使用量。这里可以通过 id 命令获取个人用户的 uid / gid 等内容。
id // 获取当前用户的 uid 等信息
通过 id 命令确认了 uid = 1002 即为当前笔者的用户 id。故而可以确定程序终止的原因是程序运行过程中发生了 OOM 导致系统向程序发送了 SIGTERM 信号。结合之前笔者发现程序总是在训练到一定的 iteration 时即结束,即可猜测是由于程序存在内存泄露问题,导致随着训练的进行,内存占用越来越大,从而最终出现 OOM。
问题复现
在获得问题的猜测之后,可以通过重新运行程序来复现,看猜测是否正确。想要确定程序在运行时的内存使用情况,可以使用 ps 或者 top,两个命令均可以显示进程的资源使用情况,其中前者输出命令执行时的系统的结果,而 top 则会显示系统动态的情况。在运行程序后,使用 top 命令获取当前运行程序的进程 id。ps 和 top 命令的结果展示如下所示,会显示进程运行时的许多信息。
PID //进程 PID
USER //进程所属的用户
PR //进程优先级
NI //Nice值,与进程调度相关
VIRT //进程使用的虚拟地址空间大小
RES //进程使用的不可交换物理地址的大小,resident memory size,如使用的 hugepage 等
SHR //使用的 shared memory 的大小
S //进程所处的状态,包括 R:running(可运行或这在运行),S:sleeping, T:traced or stopped, Z:zombie, D:uninterruptiable sleep
%CPU //CPU使用率,以时间比例计算
%MEM //使用的物理内存比例
TIME //程序开始至目前的时间
COMMAND //运行程序名
一个 top 运行时的实例如下所示,这里我们可以通过 COMMAND 找到正在运行的程序确定 PID,同时通过 VIRT 查看程序的内存使用情况。
由于 top 时动态更新的结果展示,其中会随着进程的调度等进行更新,这里主要通过 top 命令获得执行的程序的 PID,之后通过该 PID 使用 ps 命令查看程序内存的使用情况。主要借助 watch + ps + grep 的命令组合。
watch -n 1 "ps aux | grep PID" // watch 命令指定间隔 1s 执行命令,ps 命令显示进程信息,grep 用于筛选出目标进程所在的行
在笔者实验中,通过上述方式确定了程序确实存在内存占用逐渐变大的问题,需要进行调整。
具体问题
由于笔者对于代码的修改部分很小,所以比较容易的发现问题。笔者这里的原因是想要统计训练过程中的平均 loss,所以在代码中加入了类似如下的代码:
loss = L2( GT, output )
loss.backward()
total_loss += loss //统计 loss 的情况
而问题的主要原因即在于加入的求 total_loss 的代码部分。Pytorch 中计算产生的 tensor 也就是这里的 loss 默认会纳入导数计算的计算图中,后续所有使用了 loss 的计算式也会被纳入计算图中(也就时 total loss 的计算也被加入了计算图),所以关于 total_loss 部分的计算图会逐渐积累变大。在 Pytorch 中,计算图的存储位于内存中,故而也就会产生内存占用越来越大的问题。解决的办法即将 total_loss 部分从计算图中摘除,或者明确说明 total_loss 不需要进行导数运算即可,可通过 item 函数实现。Pytorch 中 item 函数会直接返回 tensor 具体的数据值,此时的 total_loss 计算过程即与 tensor 计算不相关,不需要进行梯度计算,运算过程就不会被纳入计算图的创建过程中了。
total_loss += loss.item()
参考
Pytorch model training CPU Memory leak issue
How Computational Graphs are Constructed in PyTorch
Difference between "detach()" and "with torch.nograd()" in PyTorch?