Team 甲(きのえ) 2100stepの壁

LossがNan

Lossが何(Nan)だってー！！と、叫んだかどうかは秘密です。

学習が開始されたのも束の間

事件は4/30の9:21に起きました。前日の22時近くまで最終調整をして、やっとの思いで学習を実行した次の日でした。ログに嫌な文字が見えます。

pdsh@slurm0-a3-ghpc-6: slurm0-a3-ghpc-8: ssh exited with exit code 1
pdsh@slurm0-a3-ghpc-6: slurm0-a3-ghpc-6: ssh exited with exit code 1

原因を探ってみると・・・例外の行を発見・・・

slurm0-a3-ghpc-8: Exception: Current loss scale already at minimum - cannot decrease scale anymore. Exiting run.

エラーメッセージだけだと、よく分かりませんね・・・。
例外に至った経緯を確認します。そうすると下の6行目にsteps: 2100 loss: nan...という文字が見えます。 どうやらlossがnanになってしまったらしく計算が継続できないという事らしいです。

slurm0-a3-ghpc-8:  iteration     2090/  286102 | consumed samples:      2140160 | consumed tokens:   4383047680 | elapsed time per iteration (ms): 17689.4 | learning rate: 3.000E-04 | global batch size:  1024 | lm loss: 2.795609E+00 | loss scale: 32768.0 | grad norm: 0.207 | nu
m zeros: 0.0 | actual seqlen:  2048 | number of skipped iterations:   0 | number of nan iterations:   0 | samples per second: 57.888 | tokens per gpu per second (tgs): 7409.651 | TFLOPs: 367.48 |
slurm0-a3-ghpc-6: [2024-04-29 23:58:15,370] [INFO] [loss_scaler.py:190:update_scale] [deepspeed] OVERFLOW! Rank 0 Skipping step. Attempted loss scale: 32768, but hysteresis is 2. Reducing hysteresis to 1
slurm0-a3-ghpc-6: [2024-04-29 23:58:32,656] [INFO] [loss_scaler.py:183:update_scale] [deepspeed] OVERFLOW! Rank 0 Skipping step. Attempted loss scale: 32768, reducing to 16384
slurm0-a3-ghpc-6: [2024-04-29 23:58:32,656] [INFO] [logging.py:96:log_dist] [Rank 0] step=2100, skipped=2, lr=[0.0002999628630972515, 0.0002999628630972515], mom=[(0.9, 0.95), (0.9, 0.95)]
slurm0-a3-ghpc-6: steps: 2100 loss: nan iter time (s): 17.559 samples/sec: 58.317
slurm0-a3-ghpc-8:  iteration     2100/  286102 | consumed samples:      2150400 | consumed tokens:   4404019200 | elapsed time per iteration (ms): 17711.4 | learning rate: 3.000E-04 | global batch size:  1024 | loss scale: 16384.0 | grad norm: 0.212 | num zeros: 0.0 | actual se
qlen:  2048 | number of skipped iterations:   0 | number of nan iterations:   0 | samples per second: 57.816 | tokens per gpu per second (tgs): 7400.441 | TFLOPs: 367.03 |
slurm0-a3-ghpc-8: ---------------------------------------------------------------------------------------
slurm0-a3-ghpc-8:  validation loss at iteration 2100 | lm loss value: NAN | lm loss PPL: 4.851652E+08 | 
slurm0-a3-ghpc-8: ---------------------------------------------------------------------------------------
slurm0-a3-ghpc-6: [2024-04-30 00:01:38,668] [INFO] [loss_scaler.py:183:update_scale] [deepspeed] OVERFLOW! Rank 0 Skipping step. Attempted loss scale: 16384, reducing to 8192
slurm0-a3-ghpc-6: [2024-04-30 00:01:56,057] [INFO] [loss_scaler.py:183:update_scale] [deepspeed] OVERFLOW! Rank 0 Skipping step. Attempted loss scale: 8192, reducing to 4096
slurm0-a3-ghpc-6: [2024-04-30 00:02:13,391] [INFO] [loss_scaler.py:183:update_scale] [deepspeed] OVERFLOW! Rank 0 Skipping step. Attempted loss scale: 4096, reducing to 2048
slurm0-a3-ghpc-6: [2024-04-30 00:02:30,717] [INFO] [loss_scaler.py:183:update_scale] [deepspeed] OVERFLOW! Rank 0 Skipping step. Attempted loss scale: 2048, reducing to 1024
slurm0-a3-ghpc-6: [2024-04-30 00:02:47,879] [INFO] [loss_scaler.py:183:update_scale] [deepspeed] OVERFLOW! Rank 0 Skipping step. Attempted loss scale: 1024, reducing to 512
slurm0-a3-ghpc-6: [2024-04-30 00:03:05,033] [INFO] [loss_scaler.py:183:update_scale] [deepspeed] OVERFLOW! Rank 0 Skipping step. Attempted loss scale: 512, reducing to 256
slurm0-a3-ghpc-6: [2024-04-30 00:03:22,219] [INFO] [loss_scaler.py:183:update_scale] [deepspeed] OVERFLOW! Rank 0 Skipping step. Attempted loss scale: 256, reducing to 128
slurm0-a3-ghpc-6: [2024-04-30 00:03:39,260] [INFO] [loss_scaler.py:183:update_scale] [deepspeed] OVERFLOW! Rank 0 Skipping step. Attempted loss scale: 128, reducing to 64
slurm0-a3-ghpc-6: [2024-04-30 00:03:56,373] [INFO] [loss_scaler.py:183:update_scale] [deepspeed] OVERFLOW! Rank 0 Skipping step. Attempted loss scale: 64, reducing to 32
slurm0-a3-ghpc-6: [2024-04-30 00:04:13,507] [INFO] [loss_scaler.py:183:update_scale] [deepspeed] OVERFLOW! Rank 0 Skipping step. Attempted loss scale: 32, reducing to 16
slurm0-a3-ghpc-6: [2024-04-30 00:04:13,508] [INFO] [logging.py:96:log_dist] [Rank 0] step=2110, skipped=12, lr=[0.0002999628630972515, 0.0002999628630972515], mom=[(0.9, 0.95), (0.9, 0.95)]
slurm0-a3-ghpc-6: steps: 2110 loss: nan iter time (s): 17.035 samples/sec: 60.110
slurm0-a3-ghpc-8:  iteration     2110/  286102 | consumed samples:      2160640 | consumed tokens:   4424990720 | elapsed time per iteration (ms): 34085.1 | learning rate: 3.000E-04 | global batch size:  1024 | loss scale: 16.0 | grad norm: 0.212 | num zeros: 0.0 | actual seqle
n:  2048 | number of skipped iterations:   0 | number of nan iterations:   0 | samples per second: 30.042 | tokens per gpu per second (tgs): 3845.430 | TFLOPs: 190.72 |
slurm0-a3-ghpc-6: [2024-04-30 00:04:30,605] [INFO] [loss_scaler.py:183:update_scale] [deepspeed] OVERFLOW! Rank 0 Skipping step. Attempted loss scale: 16, reducing to 8
slurm0-a3-ghpc-6: [2024-04-30 00:04:47,609] [INFO] [loss_scaler.py:183:update_scale] [deepspeed] OVERFLOW! Rank 0 Skipping step. Attempted loss scale: 8, reducing to 4
slurm0-a3-ghpc-6: [2024-04-30 00:05:04,746] [INFO] [loss_scaler.py:183:update_scale] [deepspeed] OVERFLOW! Rank 0 Skipping step. Attempted loss scale: 4, reducing to 2
slurm0-a3-ghpc-6: [2024-04-30 00:05:21,779] [INFO] [loss_scaler.py:183:update_scale] [deepspeed] OVERFLOW! Rank 0 Skipping step. Attempted loss scale: 2, reducing to 1

補足) 実行ログについて

LLMの学習に限らず、機械学習を行う場合にログはエラー等の原因を探るのに必要な情報となります。またサイズは数十万行とか数百万行とか、あるいはそれ以上かは学習の規模によって異なりますが、いずれにしても大量のログからエラーを探す必要があります。
そのため上記のログが切り取られているのは全てを貼ると大量の行数になるため必要箇所を切り貼りしています。
なおログを確認するにはlessコマンドを利用して/Errorや/Exceptionと言った形で検索をかけて、その前後を見るような形で原因等を確認していますが、マルチノードになるとログの出力順も保証されていないらしく、原因が下の方に出ていることもあります。

どうするべきか？

機械学習は確率的な問題も含まれているためnanが出ないこともあるという助言を頂いたので、そのまま再実行してみます。今回はsave intervalを600で設定しており再開する場合には1800stepで保存された状態から開始することができます。
が、1時間半後・・・再び2100stepで落ちました・・・。

何(Nan)なんだよ・・・

ギャグを言って和む雰囲気ではありません。
再現してしまったので、何かしら原因があるが、その原因とは・・・？チーム総力戦で対応にあたります。概ね以下のような対応を施します。

• Nanエラーの原因と思われる勾配の発散に関係するパラメータを変更
  • --adam-beta1 0.9 → 0.95
  • --weight-decay 0.1 → 0.3
  • --adma-eps 1e-8 → 1e-7
• 1800stepからだと時間がかかるため2030stepで一旦モデルを保存するように変更

しかし、それでも解決しませんでした。

メンバー交代

4/30の午前中から始まり対応も12時間以上を費やすメンバーもいる中、メンバー交代をして対応にあたります。明け方近くまで対応が続きます。（総格闘時間は18時間ぐらいでしょうか・・・）

ことの顛末

とりあえず、初日で日も浅かったという事もあったので、いくつかのパラメータを変更し学習率を下げて最初から学習を開始することにしました。

• fp16 → bf16に変更 (pp_size = 1 かつ no_pp = true)
• 学習率(lr) 3.0e-4 → 1.5e-4
• パイプラインパラレル：2 → 1 (=使わない)

そして次の日(5/1)の14:50時点で2290stepの学習ログが出力され、無事に2100stepの壁は超えたと判断しました。
しかし、安堵する間もなく新たな悲劇が訪れようとしていました。

この成果は、NEDO（国立研究開発法人新エネルギー・産業技術総合開発機構）の助成事業「ポスト５Ｇ情報通信システム基盤強化研究開発事業」（JPNP20017）の結果得られたものです。