zaki work log

作業ログやら生活ログやらなんやら

VS CodeのRemote DevelopmentでSSHアクセスすると接続先の高負荷状態が続く問題と対応

年末くらいから、メインの作業用Linuxマシン(この1台のみ)にVS CodeのRemote DevelopmentでSSHアクセスすると一定時間高負荷状態が続いていたので、なんとかならないかと原因調査した結果。
なお、クライアント側のVS CodeはどのPCから接続しても、特定の接続先Linuxマシンのみで高負荷になっていたので、VS CodeをインストールしているPC側の問題ではなかった ないだろうと見当をつけて調査。

VS Code version: 1.52.1

VS CodeのRemote SSHでnodeプロセスが高負荷になる

Remote Development SSHでアクセスした時のtopの状態がこちら。
接続してすぐではなく、この状態が何分も続く。(なのでマシンのファンが騒がしい…)

top - 22:00:33 up 15 days,  1:25,  1 user,  load average: 3.01, 1.73, 1.45
Tasks: 382 total,   2 running, 376 sleeping,   0 stopped,   4 zombie
%Cpu(s): 23.7 us, 18.6 sy,  0.0 ni, 57.6 id,  0.0 wa,  0.0 hi,  0.1 si,  0.0 st
KiB Mem :  7990060 total,  1515608 free,  4614492 used,  1859960 buff/cache
KiB Swap:  3670012 total,  3628028 free,    41984 used.  2947736 avail Mem 

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
3171205 zaki      20   0 2935216   2.0g  13376 R 164.1 26.7   1:53.15 node
3170035 zaki      20   0 1066544  86940  16932 S   2.7  1.1   0:05.45 node
 413552 root      20   0  231440  32184  12556 S   0.7  0.4  24:36.47 Rib
   1085 root      20   0  676336  34308   2792 S   0.3  0.4   6:45.09 containerd
 166921 root      20   0  493944  21524   3284 S   0.3  0.3   8:58.71 AgentMonitor
 413183 root      20   0  500180  23996   1972 S   0.3  0.3  19:08.39 ProcMgr-worker
1202714 zaki      20   0 1362644  77680  17112 S   0.3  1.0   7:57.84 node
3171254 zaki      20   0  162380   2532   1576 R   0.3  0.0   0:00.14 top
      1 root      20   0  193892   6664   3848 S   0.0  0.1   3:03.00 systemd
      2 root      20   0       0      0      0 S   0.0  0.0   0:00.21 kthreadd
      4 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 kworker/0:0H
      6 root      20   0       0      0      0 S   0.0  0.0   0:05.28 ksoftirqd/0
      7 root      rt   0       0      0      0 S   0.0  0.0   0:07.45 migration/0
      8 root      20   0       0      0      0 S   0.0  0.0   0:00.00 rcu_bh
      9 root      20   0       0      0      0 S   0.0  0.0   9:38.45 rcu_sched
     10 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 lru-add-drain
     11 root      rt   0       0      0      0 S   0.0  0.0   0:03.74 watchdog/0
     12 root      rt   0       0      0      0 S   0.0  0.0   0:03.72 watchdog/1

こんな感じでload averageは余裕の1超でnodeプロセスが大量にCPUを消費している。
nodeプロセスはps auxf等で確認すれば、VS CodeのRemote Developmentのサーバー側プロセスのもののであることがパスから確認できる。(パスが$HOME/.vscode-server/bin以下になっている)
そしてLinuxホストをrebootしても状況変わらず。

大量のreportファイル

さらに、何度もこの状態に遭遇しているとホームディレクトリ以下にJSON形式の謎のレポートファイルが大量に生成されている。

[zaki@cloud-dev ~]$ ls report.*
report.20201219.104229.1068593.0.001.json  report.20201222.202242.102134.0.001.json
report.20201219.104436.1068978.0.001.json  report.20201222.202458.102602.0.001.json
report.20201219.104725.1069212.0.001.json  report.20201222.203137.103212.0.001.json
report.20201219.104938.1069512.0.001.json  report.20201222.203827.9151.0.001.json
report.20201219.105220.1069896.0.001.json  report.20201222.204039.9613.0.001.json
report.20201219.105508.1070240.0.001.json  report.20201222.204240.9826.0.001.json
report.20201219.105731.1070505.0.001.json  report.20201222.204457.10034.0.001.json
report.20201219.213527.1129837.0.001.json  report.20201222.204721.10252.0.001.json
:
:
[zaki@cloud-dev ~]$ ls report.* | wc -l
122

中身を見ると、

{
  "header": {
    "reportVersion": 1,
    "event": "Allocation failed - JavaScript heap out of memory",
    "trigger": "FatalError",
    "filename": "report.20201219.104229.1068593.0.001.json",
    "dumpEventTime": "2020-12-19T10:42:29Z",
    "dumpEventTimeStamp": "1608342149806",
    "processId": 1068593,

:
:

という感じで、ヒープメモリ不足のエラーが出力されている。(ちなみにOSの搭載メモリは8GB)
手元の環境だと、20分くらい高負荷の状態が継続し、挙句にnodeプロセスがクラッシュして終了する涙
(VS CodeのRemote Development自体は使用可能)

f:id:zaki-hmkc:20210106225145p:plain

原因

いろいろ調べた結果、straceなんかで処理を眺めているとPythonのvenvディレクトリ内のファイルが大量に出力されており、どうやら「Remote Development SSHでアクセスするホストのファイルをVS Codeのファイルエクスプローラーでwatchするための情報収集」するために大量のCPU・メモリが消費されていた模様。

watchの除外設定

watch excludeで設定を検索するとでてくる「Files: Watcher Exclude」の設定に追加する。

f:id:zaki-hmkc:20210106225451p:plain

特に指定しなくてもデフォルトで以下のファイルグロブパターンは除外となっている。

    "**/.git/objects/**": true,
    "**/.git/subtree-cache/**": true,
    "**/node_modules/**": true,
    "**/.hg/store/**": true

今回、私の場合は、(venv環境は基本的にvenvというディレクトリ名・たまにvenv/a10とかvenv.hogehogeとかの配下に作ってるので)**/venv*/**という除外設定を以下のようにfiles.watcherExcludeに追加。

    "files.watcherExclude": {
        "**/venv*/**": true
    },

この設定を入れた状態でRemote Development SSHでリモートアクセスすると、今までは20分近く高負荷が続いてクラッシュしていた処理が、SSHログイン後約10はCPU負荷が高まるがすぐにIDLEに落ち着くようになった。素晴らしい。

f:id:zaki-hmkc:20210106225206p:plain

なお、似たような名前で files.exclude という設定もあるが、こちらはファイルエクスプローラー上の可視設定になっており、watch対象にするかどうかには影響しない。
(こちらに除外設定を追加してもファイルエクスプローラーから見えなくなるだけでwatch処理対象のままで負荷は高まる)

2021.08.24追記
tox使った環境だとvenvとかがパスに入らずに仮想環境が作られるようになってたので、追加して現状こんな感じ。

    "files.watcherExclude": {
        "**/venv*/**": true,
        "**/env*/**": true,
        "**/.tox/**": true
    },

(余談) なぜこんなにvenvがあるのか

まっさらなAnsible環境をわりとカジュアルにポコポコ作ることが多く、python3 -m venv hogeして、そこでpip install ansibleしていたが、これがAnsible 2.10だと(VS CodeのRemote SSHではwatchの必要もない)3万以上のファイルが作成されて、これが標準設定のRemote SSHボトルネックになっていた笑


調子戻ったなぁ。。
(というか原因究明しなかったらこの新しいVMでも同じ目にあってたな)

まとめ

というわけで、同じような症状に悩んでる方は、対象ホスト上に何らかの理由で(十万単位レベル以上の)大量のファイルを作成したりしていないか確認してみましょう。


「この大規模なワークスペースでのファイルの変更をウォッチできません。この問題を解決するには、手順のリンクに従ってください。」

についてはこちら。

code.visualstudio.com

カーネルパラメタを設定してファイル数を増やす。
/etc/sysctl.d/99-sysctl.confファイルに以下を追加。

# for vscode
fs.inotify.max_user_watches=524288

追加したらrootでsysctl -pを実行して設定反映する。