Node.js の execSync に関する一点の問題

久しぶりに水文を書きました。昨日、誰かのために Node.js の execSync という関数の特異な動作に関する問題を調べたところ、とても興味深かったので、ざっと記録しておきます。

背景#

まず、兄貴からスクリーンショットをもらいました。

問題のスクリーンショット

基本的な問題は、Node.js で execSync という関数を使って ps -Af | grep -q -E -c "\\-\\-user-data-dir=\\.+App" というコマンドを実行する際に、Node.js が時々エラーを報告するということです。具体的なスタックトレースは以下の通りです。

Uncaught Error: Command failed: ps -Af | grep -q -E -c "\-\-user-data-dir=\.+App"
    at checkExecSyncError (child_process.js:616:11)
    at Object.execSync (child_process.js:652:15) {
  status: 1,
  signal: null,
  output: [ null, <Buffer >, <Buffer > ],
  pid: 89073,
  stdout: <Buffer >,
  stderr: <Buffer >
}

しかし、同じコマンドをターミナルで実行すると、同様の現象は発生しません。したがって、この問題は少し困惑させるものです。

分析#

まず、Node.js のドキュメントにおける execSync の説明を見てみましょう。

child_process.execSync () メソッドは、一般的に child_process.exec () と同じですが、メソッドは子プロセスが完全に終了するまで戻りません。タイムアウトが発生し、killSignal が送信された場合、メソッドはプロセスが完全に終了するまで戻りません。子プロセスが SIGTERM シグナルを受け取って処理し、終了しない場合、親プロセスは子プロセスが終了するまで待機します。
プロセスがタイムアウトするか、非ゼロの終了コードを持つ場合、このメソッドは例外をスローします。Error オブジェクトには child_process.spawnSync () からの全結果が含まれます。
この関数に未処理のユーザー入力を渡さないでください。シェルのメタ文字を含む入力は、任意のコマンド実行を引き起こす可能性があります。

要するに、この関数は子プロセスを通じてコマンドを実行し、コマンドの実行がタイムアウトするまで待機します。問題ありません。それでは、上記のエラースタックと execSync の実装コードを見てみましょう。

function execSync(command, options) {
  const opts = normalizeExecArgs(command, options, null);
  const inheritStderr = !opts.options.stdio;

  const ret = spawnSync(opts.file, opts.options);

  if (inheritStderr && ret.stderr)
    process.stderr.write(ret.stderr);

  const err = checkExecSyncError(ret, opts.args, command);

  if (err)
    throw err;

  return ret.stdout;
}

function checkExecSyncError(ret, args, cmd) {
  let err;
  if (ret.error) {
    err = ret.error;
  } else if (ret.status !== 0) {
    let msg = 'Command failed: ';
    msg += cmd || ArrayPrototypeJoin(args, ' ');
    if (ret.stderr && ret.stderr.length > 0)
      msg += `\n${ret.stderr.toString()}`;
    // eslint-disable-next-line no-restricted-syntax
    err = new Error(msg);
  }
  if (err) {
    ObjectAssign(err, ret);
  }
  return err;
}

ここで、execSync はコマンド実行後に checkExecSyncError に入って、子プロセスの Exit Status Code が 0 でない場合、コマンド実行にエラーがあったと見なして例外をスローします。

問題はなさそうです。つまり、コマンドを実行する際にエラーが発生したということですね？それでは、確認してみましょう。

このような Linux の Syscall 問題のトラブルシューティングツールについては（この問題は Mac などの環境でも存在しますが、調査を簡単にするために Linux で再現しました）、strace 以外にもっと成熟した便利なツールは見つかりません（eBPF に基づくものもありますが、正直自分で書くよりも strace の方が効果的です）。

コマンドを実行します。

sudo strace -t -f -p $PID -o error_trace.txt

tips: strace を使用する際は、-f オプションを利用して、トレースされたプロセスが作成した子プロセスをトレースできます。

コマンドを実行し、全ての syscall の呼び出しチェーンを取得しました。さあ、分析を始めましょう。

まず、最も重要な部分に目を向けます（ファイル全体が非常に長いため、約 4K 行ありますので、重要な部分だけを分析します）。

...
894259 13:21:23 clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f12d9465a50) = 896940
...
896940 13:21:23 execve("/bin/sh", ["/bin/sh", "-c", "ps -Af | grep -E -c \"\\-\\-user-da"...], 0x4aae230 /* 40 vars */ <unfinished ...>
...
896940 13:21:24 <... wait4 resumed>[{WIFEXITED(s) && WEXITSTATUS(s) == 1}], 0, NULL) = 896942
896940 13:21:24 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=896942, si_uid=1000, si_status=1, si_utime=0, si_stime=0} ---
896940 13:21:24 rt_sigreturn({mask=[]}) = 896942
896940 13:21:24 exit_group(1)           = ?
896940 13:21:24 +++ exited with 1 +++

ここで、Node.js は直接 fork を使用して新しいプロセスを作成するのではなく、clone を使用して新しいプロセスを作成していることを知っておきましょう。両者の違いについて詳しく説明するには、別の長い記事が必要です（ここでは公式の説明を簡単に述べます）。

これらのシステムコールは、新しい（「子」）プロセスを作成しますが、fork (2) に似た方法で行われます。fork (2) と比較して、これらのシステムコールは、呼び出しプロセスと子プロセスの間で共有される実行コンテキストの部分をより正確に制御することができます。たとえば、これらのシステムコールを使用すると、呼び出し元は、2 つのプロセスが仮想アドレス空間、ファイルディスクリプタのテーブル、およびシグナルハンドラのテーブルを共有するかどうかを制御できます。これらのシステムコールは、新しい子プロセスを別の名前空間に配置することも可能です。

簡潔に言えば、clone は fork に近い意味を提供しますが、clone を使用することで、開発者はプロセス / スレッド作成プロセスの詳細をより細かく制御できます。

さて、ここで 894259 という親プロセスが clone を使用して 896940 というプロセスを作成しました。実行中に、896940 というプロセスは execve という syscall を使用して sh（これは execSync のデフォルトの動作です）を介して私たちのコマンド ps -Af | grep -q -E -c "\\-\\-user-data-dir=\\.+App" を実行します。さて、896940 が終了する際に、確かに 1 の exit code で終了したことがわかります。これは以前の分析と一致します。つまり、コマンドを実行する際にエラーが発生したということです。では、このエラーはどこで発生したのでしょうか？

コマンドを分析してみましょう。一般的なシェルに精通している方は気づくかもしれませんが、実際に私たちのコマンドにはパイプ操作子 | が使用されています。正確には、この操作子が出現すると、前後の 2 つのコマンドはそれぞれ別のプロセスで実行され、パイプを介して IPC が行われます。つまり、これらの 2 つのプロセスをすぐに特定できます。テキストを直接検索しました。

...
896941 13:21:23 execve("/bin/ps", ["ps", "-Af"], 0x564c16f6ec38 /* 40 vars */) = 0
...
896942 13:21:23 execve("/bin/grep", ["grep", "-E", "-c", "\\-\\-user-data-dir=\\.*"], 0x564c16f6ecb0 /* 40 vars */ <unfinished ...>
...
896941 13:21:24 <... exit_group resumed>) = ?
896941 13:21:24 +++ exited with 0 +++
...
896942 13:21:24 exit_group(1)           = ?
896942 13:21:24 +++ exited with 1 +++

ここで、896942 は grep を実行するプロセスで、直接 exit code 1 で終了しました。では、なぜでしょうか？grep の公式ドキュメントを見たところ、驚きました。

通常、選択された行が見つかった場合、終了ステータスは 0 であり、そうでない場合は 1 です。ただし、エラーが発生した場合は終了ステータスは 2 ですが、-q または --quiet または --silent オプションが使用され、選択された行が見つかった場合は 1 です。ただし、POSIX は、grep、cmp、diff などのプログラムに対して、エラーが発生した場合の終了ステータスが 1 より大きいことを義務付けているため、移植性のために、厳密に 2 と等しいことをテストするのではなく、この一般的な条件をテストするロジックを使用することをお勧めします。

もし grep がデータをマッチさせなかった場合、exit code 1 でプロセスを終了します。マッチした場合は 0 で終了します。しかし、しかし、驚きました、驚きました。標準的な意味に従えば、exit code 1 の意味は Operation not permitted ではないのですか？基本的な法則に従っていない！

まとめ#

実際に通読してみると、2 つの理由をまとめることができます。

Node.js は POSIX 関連 API を抽象化して封装する際、標準的な意味に従ってユーザーを保護しました。理論的には、これはアプリケーションの自己決定的な動作であるべきです。
grep が基本的な法則に従っていない。

正直なところ、これらの 2 つの側面のどちらがより厄介かを評価する方法はわかりません。前述のように、子プロセスの exit code を処理することは理論的にはアプリケーションの自己決定的な動作であるべきですが、Node.js 自体が一層の封装を行い、ユーザーの心的負担を軽減する一方で、非標準的なシナリオに直面すると、かなりのリスクが生じることになります。

異なるシナリオに応じてトレードオフを行うしかないと言えるでしょう。

さて、この記事はここまでです。急遽書いたので、関連する参考文献を文中に列挙するのは面倒です。これくらいでいいでしょう、水文の目標達成.jpg