(この記事は自サイトとのクロスポストです。)
初心者丸出し感がものすごいのですが、標題の通りのことが起こってしまいました。とあるJavaScript製の自作ソフトウェアの文法チェックにeslintやjsonlint-cliを使いたくて、package.json
を置いておいて、npm install
でそれらをインストールできるようにしていたのですが、それが突然以下のようなエラーで止まるようになってしまいました。
$ npm install
npm ERR! invalid options argument
npm ERR! A complete log of this run can be found in:
npm ERR! /root/.npm/_logs/2021-05-xxTxx_xx_xx_xxxZ-debug.log
他の自作ソフトウェアでも、npm install
しようとすると同じエラーで止まってしまいました。メッセージには、詳細を見たければログを読むように書かれており、そのログファイル(/root/.npm/_logs/2021-05-xxTxx_xx_xx_xxxZ-debug.log
)を見ると、具体的なエラー箇所は以下のような感じでした。
27 verbose stack TypeError: invalid options argument
27 verbose stack at optsArg (/usr/local/lib/node_modules/npm/node_modules/mkdirp/lib/opts-arg.js:13:11)
27 verbose stack at mkdirp (/usr/local/lib/node_modules/npm/node_modules/mkdirp/index.js:11:10)
27 verbose stack at tryCatcher (/usr/local/lib/node_modules/npm/node_modules/bluebird/js/release/util.js:16:23)
27 verbose stack at ret (eval at makeNodePromisifiedEval (/usr/local/lib/node_modules/npm/node_modules/bluebird/js/release/promisify.js:184:12), <anonymous>:13:39)
27 verbose stack at Object.mkdirfix (/usr/local/lib/node_modules/npm/node_modules/npm-registry-fetch/node_modules/cacache/lib/util/fix-owner.js:36:10)
27 verbose stack at makeTmp (/usr/local/lib/node_modules/npm/node_modules/npm-registry-fetch/node_modules/cacache/lib/content/write.js:121:19)
27 verbose stack at write (/usr/local/lib/node_modules/npm/node_modules/npm-registry-fetch/node_modules/cacache/lib/content/write.js:35:19)
27 verbose stack at putData (/usr/local/lib/node_modules/npm/node_modules/npm-registry-fetch/node_modules/cacache/put.js:11:10)
27 verbose stack at Object.x.put (/usr/local/lib/node_modules/npm/node_modules/npm-registry-fetch/node_modules/cacache/locales/en.js:28:37)
27 verbose stack at WriteStream._flush (/usr/local/lib/node_modules/npm/node_modules/npm-registry-fetch/node_modules/make-fetch-happen/cache.js:156:21)
27 verbose stack at WriteStream._write (/usr/local/lib/node_modules/npm/node_modules/flush-write-stream/index.js:36:35)
27 verbose stack at doWrite (/usr/local/lib/node_modules/npm/node_modules/flush-write-stream/node_modules/readable-stream/lib/_stream_writable.js:428:64)
27 verbose stack at writeOrBuffer (/usr/local/lib/node_modules/npm/node_modules/flush-write-stream/node_modules/readable-stream/lib/_stream_writable.js:417:5)
27 verbose stack at WriteStream.Writable.write (/usr/local/lib/node_modules/npm/node_modules/flush-write-stream/node_modules/readable-stream/lib/_stream_writable.js:334:11)
27 verbose stack at WriteStream.end (/usr/local/lib/node_modules/npm/node_modules/flush-write-stream/index.js:45:41)
27 verbose stack at WriteStream.end (/usr/local/lib/node_modules/npm/node_modules/flush-write-stream/index.js:42:47)
依存関係のどこかで、あるライブラリの動作が変更され、それに依存していた別のライブラリが動作しなくなる、という事態は度々発生します。RubyでもNode.js(JavaScript)でも、おそらくはPHPでもPythonでも、パッケージマネージャを使っていると、「色々なライブラリが依存関係で自動的に入ってくるけれども、そのそれぞれの内容はチンプンカンプン。にもかかわらず、依存関係が原因の実行時エラーが発生してしまって問題解決の糸口すら掴めない」という状況が発生しがちでしょう。
筆者はJavaScriptを長く書いてきてはいますが、パッケージマネージャそのものには明るくなく、このような状況が発生するとお手上げになりがちで、そういう意味ではまったく初心者レベルと言えます。今回も、エラーが出た瞬間に顔が真っ青になり、操作を繰り返しても状況が変わらないことでさらに血の気を失う、という絶望的な状況でした。
結論から先に言うと、この問題はNode.jsを入れるのに使っていたnのバージョンが古かったせいで発生していました。n自体を最新の物に入れ換えてn 16.1.0
で現行の最新リリースのNode.jsを入れ直した所、この問題は無事に解消され、npm install
が成功するようになりました。
以下は、今回この問題の解決策に辿り着き、原因を把握するまでの過程で行ったことの記録です。今回の問題自体は、誰の環境でも起こるという物ではないので、直接の参考にはならないと思いますが、未知の物と立ち向かいながら調査をして、現状を把握し問題解決を図る際の、暗闇の歩き方の参考にしてもらえれば幸いです。
最初にやったこと:先行事例をググる
エラーメッセージが出ている時は、そのメッセージでWeb上を検索するのが基本です。すでに誰かが同じ問題で躓いていて、StackOverflow等に質問が投稿されていれば、回答を参照できるかも知れません。また、もしいずれかのライブラリの不具合だったのであれば、イシュートラッカーに解決策が書かれている可能性もあります。
ということで TypeError: invalid options argument
で検索してみると、node-export-serverというプロジェクトのissueが見つかりました。スタックトレースに現れている関数名もよく似ています。報告の内容は「highcharts-export-serverが動作しない」というもので、当該プロジェクトにおいては、依存関係に含まれていたパッケージが古く、依存関係を更新して問題を解消した(highcharts-export-serverをそれより後のバージョンに更新すれば問題が解消される)ようでした。
筆者の状況では、すでに依存ライブラリをインストール済みの所では、インストールされたライブラリやコマンドは期待通りに動きます。あくまで新規のnpm install
のみの失敗です。ということは、パッケージマネージャであるnpmの動作自体がおかしくなっているようです。見つけた事例と筆者の事例は状況が異なっていますが、「対象ソフトウェア自体を新しい物に更新すれば問題が解消される」という可能性はありそうです1。
今回問題が起こっているnpmコマンドは、Node.js導入時に一緒にインストールされたものです。問題の環境はRaspbianですが、aptで入るNode.js(とnpm)は古すぎるため、nを使って、より新しいバージョンを使っています2。このとき入っていたNode.jsのバージョンは13.14.0でしたが、最新リリース版は16.1.0、長期安定版(LTS)でも14.16.1と、だいぶ古い物になってしまっていたので、とりあえずsudo n 16.1.0
で最新のNode.jsとnpmにアップデートしてみました。
その後もう一度npm install
してみたのですが……結果は変わらず、当初とまったく同じエラーが出てしまいました。
次にやったこと:何度もやり直してみる
最初に書いたとおり筆者はNode.jsのパッケージ管理周りは全然素人なので、こうなるともうお手上げです。なので、カレントディレクトリのnode_modulesや~/.npm/を消してはnpm install
し直す操作を何度も繰り返す、という猿みたいな行動に出てしまいました。
一応、そうすることにまったく根拠が無かったわけでもありません。パッケージマネージャでリモートからパッケージをダウンロードしてきてインストールする状況だと、パッケージリポジトリのWebサイトが過負荷だとか不調だとか、依存関係の中のソフトウェアの1つが今まさに作者の手で更新されている最中だとか、自分ではどうしようもない理由でインストールに失敗することがあります。実際、スタックトレースの中に、tarのファイルを展開する処理の中である事を示唆するような内容があったので、例えば、npm install
でインストールしようとしているライブラリのパッケージの取得に失敗していて、その結果空のファイルが作成されてしまい、ファイルを展開しようとして想定外の状況が発生している、という可能性もありそうに思えました3。
ということで、何度もリトライしてみて、埒が開かず不貞寝して、一晩おいてもう一度何度もリトライをしてみて、ということをしてみたのですが、やはり結果は変わらずでした。リトライ中には、何度か同じ操作を繰り返してみると、エラーの出る箇所が微妙に変わったりもして、やっぱりリモートの不調なのか?とも思えたのですが4、10回ほど繰り返してみても、同じパターンのエラーメッセージが繰り返し現れる感じだったので、この方法では駄目だと諦めるしかありませんでした。
最後にやったこと:真面目に原因を調べる
ググってもまったく同じ状況の情報には辿り着けない。何度リトライしてみても状況は変わらない。事ここに至って、ようやく重い腰を上げて、ちゃんと掘り下げて原因を調べてみることにしました。
スタックトレースから原因箇所を見てみる
調査の手がかりはスタックトレースです。エラー箇所を上から順に見ていきます。
27 verbose stack TypeError: invalid options argument
27 verbose stack at optsArg (/usr/local/lib/node_modules/npm/node_modules/mkdirp/lib/opts-arg.js:13:11)
27 verbose stack at mkdirp (/usr/local/lib/node_modules/npm/node_modules/mkdirp/index.js:11:10)
27 verbose stack at tryCatcher (/usr/local/lib/node_modules/npm/node_modules/bluebird/js/release/util.js:16:23)
27 verbose stack at ret (eval at makeNodePromisifiedEval (/usr/local/lib/node_modules/npm/node_modules/bluebird/js/release/promisify.js:184:12), <anonymous>:13:39)
27 verbose stack at Object.mkdirfix (/usr/local/lib/node_modules/npm/node_modules/npm-registry-fetch/node_modules/cacache/lib/util/fix-owner.js:36:10)
27 verbose stack at makeTmp (/usr/local/lib/node_modules/npm/node_modules/npm-registry-fetch/node_modules/cacache/lib/content/write.js:121:19)
...
最も最初に現れているoptsArg()
という関数の、例外を上げている箇所は、以下のようになっていました。
const optsArg = opts => {
if (!opts)
opts = { mode: 0o777, fs }
else if (typeof opts === 'object')
opts = { mode: 0o777, fs, ...opts }
else if (typeof opts === 'number')
opts = { mode: opts, fs }
else if (typeof opts === 'string')
opts = { mode: parseInt(opts, 8), fs }
else
throw new TypeError('invalid options argument') // ←この行で例外発生
...
どうも、関数に渡された引数のopts
の内容が想定外の物だと、この例外が上がるようです。
試しに、この関数の出だしの所にconsole.log('opts: '+opts);
のようなコードを仕込んでnpm install
を再実行してみた所、エラーログからは、何らかの関数オブジェクトが渡されてきていることが読み取れました。その場合、!opts
は偽になり、typeof opts
は"function"
で、いずれの条件分岐にも引っかからないので、最後のthrow new TypeError(...)
が実行されるのも道理です。
呼び出し元のmkdirp()
は、以下のようになっています。
const mkdirp = (path, opts) => {
path = pathArg(path)
opts = optsArg(opts) // ←この行で例外発生
...
mkdirp()
自体の第2引数として渡された物をそのままoptArg()
に渡していました。さらに呼び出し元を辿ってみます。今度はbluebirdというライブラリのtryCatcher()
という関数です。
function tryCatcher() {
try {
var target = tryCatchTarget;
tryCatchTarget = null;
return target.apply(this, arguments); // ←この行で例外発生
...
……途端に訳が分からなくなりました。メタプログラミング的な事をするライブラリのようで、動作を理解するのは骨が折れそうです。スタックトレースの次の行も同様にメタプログラミング臭がしたので、一つ飛ばして、さらに上位の呼び出し元のcacacheというライブラリのObject.mkdirfix()
を見てみました。
function mkdirfix (p, uid, gid, cb) {
return mkdirp(p).then(made => { // ←この行で例外発生
if (made) {
return fixOwner(made, uid, gid).then(() => made)
}
...
あれっ!? mkdirp()
の第2引数に想定外の値が渡ってきていることがエラーの原因だったはずなのに、肝心の呼び出し元では第1引数しか渡していないではないですか!!
見えてきたこと
この謎は、間に挟まっていたBluebirdというライブラリのことを調べると解けました。紹介記事を参照した所、BluebirdはPromiseの機能強化版のような物らしく、そこに「コールバック関数を受け取る形の関数を、Promiseを返す関数に変換する」という機能も含まれているようでした。
そのことを頭に入れてObject.mkdirfix()
を定義しているファイルの先頭の方を見てみると、
const BB = require('bluebird')
const chownr = BB.promisify(require('chownr'))
const mkdirp = BB.promisify(require('mkdirp')) // ←ここ
const inflight = require('promise-inflight')
...
確かに、require('mkdirp')
してきたmkdirp()
ではなく、それをBluebirdがラップした物を使っているようです。
JSのPromiseというと、
async function f() {
return new Promise((resolve, reject) => {
// この関数は、処理完了時には第1引数のコールバック関数を、
// エラー時には第2引数のコールバック関数を呼ぶ物であると仮定する。
asyncFunction(resolve, reject);
});
}
のようにして、コールバック関数としてリゾルバー関数(resolve()
)を呼んだ時点でPromiseが解決される、という形で、コールバック関数を使う処理をPromiseを返す処理に書き換える使い方をする物です。ちゃんとは調べていませんが、BB.promisify()
はおそらく「渡された関数の最後の引数に、自動的にコールバック関数としてリゾルバーを渡すようにして、それが実行される事を期待する」もので、そのリゾルバーが先のoptsArg()
に渡ってきてopts
として見えていたのでしょう。
つまり、
- mkdirpが提供する
mkdirp()
は、過去のバージョンではコールバック関数を受け付ける仕様だった。 - どこかのバージョンで仕様が変わって、
mkdirp()
はそれ自体がPromiseを返すようになった。 - cacacheは古いバージョンのmkdirpに依存しており、
mkdirp()
はコールバック関数を使う仕様であると想定した設計になっている。そのため、不必要にmkdirp()
をBluebirdでPromise化してしまっている。 - コールバック関数を受け付けない仕様の
mkdirp()
が、BluebirdによってPromise化され、第2引数としてPromiseのリゾルバーを渡された状態で実行された結果、実行時エラーが発生してしまっている。
という状況のようです。
さらに調べてみた所、cacacheの現行バージョンはすでにこの問題が修正されており、mkdirp()
がPromiseを返す前提の設計に改まっているようでした。ということは、古いバージョンのcacacheが何故か使われてしまっているのが、今回のエラーを引き起こしている原因ということになります。
実際、スタックトレースに現れていたcacache(/usr/local/lib/node_modules/npm/node_modules/npm-registry-fetch/node_modules/cacache
)のpackage.json
を見てみると、バージョンは10.0.4でした。不要なPromise化をなくす変更はObject.mkdirfix()
を定義しているファイルに対する最後のコミットで行われていて、この修正が含まれているのはバージョン14.0.0以降(現行最新版は15.0.6)なので、「cacacheが異常に古い状態である」ということは間違い無いようです。
古いcacacheの出所を辿る
npmパッケージ同士の依存関係は、そのパッケージが含まれているnode_modules
ディレクトリの上位ディレクトリにあるpackage.json
のdependencies
プロパティを見ると把握できます。新しいmkdirpと互換性が無い古いcacacheを要求しているのは、一体誰なのでしょうか。
nでインストールされたnpmは、/usr/local/lib/node_modules/npm
配下にありますが、この古いバージョンのcacacheは、npmが直接依存しているのではなく、npmが依存しているnpm-registry-fetchの依存関係として、/usr/local/lib/node_modules/npm/node_modules/npm-registry-fetch/node_modules/cacache
の位置にインストールされています。ということで、その上位の/usr/local/lib/node_modules/npm/node_modules/npm-registry-fetch
配下でcacacheに依存している物を探してみたのですが、
$ cd /usr/local/lib/node_modules/npm/node_modules/npm-registry-fetch
$ grep -r cacache | grep package.json
./package.json: "cacache": "^15.0.0",
と、npm-registry-fetch以外誰も依存しておらず、また依存バージョンも新しめの物が指定されていることがわかりました。あっれぇ!?!? おかしいな!?!?!!? 誰もこんな古いバージョンを要求してないぞ!?!?!!?!?
依存関係で指定されたバージョンより古いバージョンが敢えてインストールされるということは、通常考えられません。また、そもそも、このnpm(/usr/local/lib/node_modules/npm
)はnによってインストールされた物なので、npmによる依存関係の解決も行われていないはずです。
ということは、この古いcacacheを置いている犯人は、nである疑いが濃厚です。
nによってインストールされたNode.jsは、/usr/local/n/versions/node
配下に実体があり、sudo n 16.1.0
のようにしてバージョンを切り替えると、都度/usr/local/bin
や/usr/local/lib/node_modules
にファイルを置くようになっているようです。一緒に切り替えられるnpmも、/usr/local/n/versions/node/16.1.0/lib/node_modules/npm
などの位置にある物が使われるようです。
ところが、/usr/local/n/versions/node/16.1.0/lib/node_modules/npm
配下を見てみても、古いバージョンのcacacheは影も形もありません。sudo n 16.1.0
でバージョンを切り替えるときに、nが自分で古いバージョンのcacacheをダウンロードしてきている、とでもいうのでしょうか? まさか、そこまで凝ったことをするようなツールだとは思えないのですが……
そこで、今度はn自体のことをもうちょっと調べてみることにしました。
nの正体
そもそも、筆者はnがどういう物かよく分からないまま使っていました。
システムのパッケージを無視して新しいNode.jsを使う方法としては、今はnodistやnodenvを使うのがトレンドみたいですが、筆者がこの環境を作った当時は「nvmはもう古い、これからはnの時代や!」みたいな感じでした。導入手順は、
- システムのNode.jsをインストールする。
-
sudo npm -g install n
でn
コマンドをインストールする。 - システムのNode.jsをアンインストールする。
-
sudo n latest
で最新のNode.jsをインストールする。
という要領で、npmパッケージなのに何故かNode.js本体を必要としない不思議なツールです。
今回初めてn
コマンドの実体の中身を見てみて把握したのですが、これって実は単一のBashスクリプトだったんですね。Bashスクリプトを簡単にインストールできる形で配布する一般的な手段がないから、配布手段としてnpmパッケージにしてあるというだけなんだ、ということを筆者はようやく把握しました。
Bashのシェルスクリプトなら、筆者には多少は覚えがあるので、中を読むこともできそうです。というわけでGitHub上の物を読み始めてみたのですが、これといって問題を引き起こしていそうな箇所は見当たりません。ふとバージョン表記を見てみると、最新版は7.2.2となっています。そこで、問題の環境のnのバージョンを見てみると、
$ n --version
2.1.7
と、ずいぶん古い物になっていました。もしかしたら、n自体を新しい物に入れ換えてみれば、状況が改善するかもしれません。
ただ、nはsudo npm -g install n
でインストールするのですが、この環境のnpmコマンドはエラーで動かず、単独のパッケージのインストールすらもできない状態です。幸い、リポジトリにあったMakefileを見てみると、make install
でもインストールできるようでしたので、
$ git clone https://github.com/tj/n.git
$ cd n
$ sudo make install
と、最新版を持ってきてインストールしてみました。
その上で改めてsudo n 16.0.0
などとして最新以外のNode.jsをアクティブにし、sudo n rm 16.1.0
でバージョンを一旦削除して、sudo n 16.1.0
で最新のNode.jsを入れ直してみると……npm installが成功するようになりました!! ひゃっほう!!!!
真の原因
問題が無事解決したので、これで終わりとしてもいいのですが、そもそも何故古いnで問題が起こっていたのか。問題が起こっていたときのバージョンのnの実装を、インストールから指定バージョンの有効化まで辿ってみたところ、原因が分かりました。
指定バージョンを有効化する処理は以下の通り実装されていましたが、
activate() {
local version=$1
check_current_version
if test "$version" != "$active"; then
local dir=$BASE_VERSIONS_DIR/$version
for subdir in bin lib include share; do
if test -L "$N_PREFIX/$subdir"; then
find "$dir/$subdir" -mindepth 1 -maxdepth 1 -exec cp -fR "{}" "$N_PREFIX/$subdir" \;
else
cp -fR "$dir/$subdir" $N_PREFIX # ←ここ
fi
done
disable_pax_mprotect "$N_PREFIX/bin/node"
fi
}
ここで、それまでアクティブだったバージョンのファイルを削除しないまま、cp -fR
で、これからアクティブにするバージョンのファイルをコピーしています5。
cpコマンドは、コピー先に同じ名前のファイルがあれば上書きしますが、それ以外については可能な限り元あったファイルを維持します。コピー元になくコピー先にだけあったファイルも、削除される事なくそのまま残ります。
つまり、こういう状況だったわけです。
- nで古いバージョンのNode.jsをインストールした際に、そのときの古いバージョンのcacacheが
/usr/local/lib/node_modules/npm/node_modules/npm-registry-fetch/node_modules/cacache
の位置に置かれた。 - nで新しいバージョンのNode.jsとnpmをインストールしたが、それらのバージョンには、この位置にcacacheが含まれていなかった。
- 結果、新しいバージョンのNode.jsとnpmをインストールしても、古いcacacheがいつまでも残留して、そちらが読み込まれてしまっていた。
- nは
sudo n 16.0.0
のようにしてバージョンを削除できるが、これで削除できるのは/usr/local/n/versions
配下にある物だけで、現在使用中のバージョンは削除できない。(古いバージョンの)nを使っている限り、/usr/local/lib/node_modules/npm/node_modules/npm-registry-fetch/node_modules/cacache
は削除される機会が無く、削除する方法もない。 - 何かのタイミングで、
sudo n latest
のようにして新しいバージョンのNode.jsをインストールしたときに、この問題が起こり得る状態になっていた。しかし、すでにnpm install
済みの物を使っている限りは、npmを実行することもなかったため、気付いていなかった。今回、rm -r node_modues
してnpm install
し直したことで、初めて問題に気が付いた。(「何もしてないのに急にnpm install
できなくなった」という、直近で行った操作と現象の関係性が分からない状況は、このせいで発生していた。)
以上、ようやくすべての謎が解けました。
今回のことから得られた教訓
- ググって答えが出なくても、諦めずにちゃんと真面目に調べよう。答えは手元の環境に潜んでいる。
- バージョン管理ツールが何をしているのか、ちゃんと把握しておこう。
- 使っているソフトウェアは、ちゃんとバージョンアップしておこう。バージョン管理ツール自体も含めて。
躓きが発生したとき、最短の方法で問題解決に至れないと、「これだからNode.jsは嫌なんだ!!」とか「JavaScriptは嫌いだ!!」とか、的外れな八つ当たりをして諸々のことを投げ出して、「やっぱりPythonだよな!」とか「Docker最高!」とか、すでに自分が使ったことのある別のソリューションや、正体をよく把握できていない便利ツールへの依存をただただ深めてしまうことは、よくあるのではないかと思います。
ですが、そういうときこそ、逃げずに問題に真正面から立ち向かってみることで、新しい知見を得て技術者としての見聞を広められるチャンスになるのではないか、と筆者は考えています。
実際の所、問題に真正面から立ち向かうのは、早急に問題の解決を図るという意味では、大抵は非効率的です。特に今回のように、よく分からない原因で環境が壊れてしまったケースでは、深入りせずにそんな環境とっとと捨ててしまって、ゼロから作り直す方が安全確実です。DockerやAnsibleといった類の技術は、まさにそのために作られたと言っていいです。にもかかわらず、それを使わないで馬鹿正直に問題に立ち向かうのは、賢い選択とは見なされにくいでしょう。
でも、もし時間に猶予があって、今まで一度も深入りしたことがなかったのなら、一度くらいは問題に真面目に立ち向かってみて、見聞を広めてみてもいいんじゃないか、と筆者は思います。
そうして「今まで真っ暗闇にしか見えなかった物が、実は理解可能な物だと分かってきた」という体験を繰り返すと、暗闇に飛び込むことも、次第に怖くなくなってきます。誰も立ち入ってこなかった領域にも、さほど勇気を要さずに踏み込めるようになります。多くの人が未知の物への恐怖で引き返す場面で、ためらわず先に進めるのであれば、それは技術者として何かのアドバンテージになるのではないでしょうか。それは、「失敗」を避け、すでに誰かが導き出した「正解」だけを丁寧になぞっていく、というやり方では身に着けにくい能力なのではないでしょうか。
ゴールデンウィークの最終日を潰して、一銭の得にもならない、益体もない調査をしたことに、筆者はそのように意味を見出してみている次第です。