Pytorch 训练停止，输出显示 died with <Signals,SIGKILL.9> 问题定位过程记录

　　最近使用 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?

　　How can i process multi loss in pytorch?