まだプログラマーですが何か?

プログラマーネタとアスリートネタ中心。たまに作成したウェブサービス関連の話も http://twitter.com/dotnsf

タグ:error

タイトルどおりの内容のエラーが発生したので、その原因と解決策を探った記録をブログにまとめました。

環境としては以下の図のようなものです。1台の Windows 10 PC の中に Docker Desktop を導入・起動し、MySQL サーバーのイメージからコンテナを作って 3306 番ポートで公開起動しました。この環境に WSL(2) の MySQL CLI を使って、localhost:3306 の MySQL サーバーにログインする、というだけの内容なのですが、ログイン時にコネクションエラーが発生してしまう、という症状が出ていました:
20210612


具体的に紹介します。今回使った MySQL のコンテナイメージはこちらです。厳密には mariadb を使っています。同様の現象が発生すると思うので、他の MySQL 系イメージでも構いません:
https://hub.docker.com/r/linuxserver/mariadb


Docker Desktop を使ってこのイメージからコンテナを作成します。WSL を起動するなどして docker コマンドが使える状態で以下のコマンドを実行します(目的は Docker Desktop 内のコンテナとして起動することなので、このコマンド自体は WSL から実行しなくても構いません):
$ docker run -d --name=mariadb -e PUID=1000 -e PGID=1000 -e MYSQL_ROOT_PASSWORD=root -e TZ=Asia/Tokyo -e MYSQL_DATABASE=mydb -e MYSQL_USER=user -e MYSQL_PASSWORD=P@ssw0rd -p 3306:3306 --restart unless-stopped linuxserver/mariadb

こんな感じで、Docker Desktop 内のコンテナとして MySQL が起動します:
2021061301


指定したオプションはコンテナイメージのドキュメントを参考に指定しています。上の例では root のパスワードは root 、利用ユーザーは user 、利用ユーザーのパスワードは P@ssw0rd 、利用データベース名を mydb、コンテナ名は mariadb、などを指定しています(適当に変更いただいても構いません)。ポート番号に -p 3306:3306 を指定しているので、ローカルホストの 3306 番ポートからも(公開されているので)アクセスできるはずです。事前準備はここまで。

ではこの方法で Docker Desktop 内に起動した MySQL(mariadb) に、WSL から MySQL CLI で接続してみます。上述のオプションであれば以下のコマンドで接続できるはずです:
$ mysql -u user -pP@ssw0rd -h localhost mydb

しかし実際には以下のようなエラーが表示されてしまいます:
$ mysql -u user -pP@ssw0rd -h localhost mydb
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (2 "No such file or directory")

ユーザー名やパスワード、データベース名は間違っておらず、接続先も localhost だから間違えようがないはずです。ポート番号もデフォルトの 3306 のままなので特別なオプションも不要のはず・・・ ではなぜエラーになってしまうのでしょうか?


改めてエラーメッセージをよく見ると "Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock'" と表示されています。ちなみにこのファイルは存在していません(/var/run/mysqld というディレクトリが存在していません):
$ ls -la /var/run/sqld/mysqld.sock
ls: cannot access '/var/run/sqld/mysqld.sock': No such file or directory

このエラーメッセージでわかる人もいると思うのですが、MySQL コマンドは localhost が対象の場合はデフォルトで「ソケット接続」という方法で接続を試みます。そしてこのソケット接続をする場合の情報を /var/run/sqld/mysqld.sock というファイルで管理しているため、このファイルを読み込もうとしているのでした。

しかし、今回の環境では WSL 内には MySQL サーバーは起動していません。WSL 内からの docker コマンドで起動してはいますが、実体は Windows にインストールされた Docker Desktop のコンテナとして起動しています。要は「WSL と同じマシン上で動いてはいて、ポートも公開されているけど、WSL から直接ソケット接続できる状態で動いていない」のです。これがエラーの原因で、エラーメッセージの理由でもあります。

では、エラーなしに WSL から MySQL に接続するにはどのようなコマンドにすればいいでしょうか? 答はシンプルで「ソケット接続ではなく、TCP 接続するようなオプションを指定」することで解決できます。具体的には以下のように --protocol=TCP オプションを付けて実行します:
$ mysql -u user -pP@ssw0rd --protocol=TCP -h localhost mydb
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 11
Server version: 10.4.18-MariaDB-1:10.4.18+maria~bionic-log mariadb.org binary distribution

Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MariaDB [mydb]>

今度は無事に接続できました。「localhost の罠」にかかった時の話でした。


Node.js を使ったアプリケーション開発中に npm install を実行して、こんなエラーに遭遇することがあります(個人的な印象では下の例のように canvas モジュールをインストールしようとした際によく遭遇します):
$ npm install canvas

> canvas@1.6.11 install /Users/dotnsf/src/tmp/node_modules/canvas
> node-gyp rebuild

gyp WARN download NVM_NODEJS_ORG_MIRROR is deprecated and will be removed in node-gyp v4, please use NODEJS_ORG_MIRROR
gyp ERR! configure error 
gyp ERR! stack Error: Python executable "/Users/dotnsf/.pyenv/shims/python" is v3.6.5, which is not supported by gyp.
gyp ERR! stack You can pass the --python switch to point to Python >= v2.5.0 & < 3.0.0.
gyp ERR! stack     at PythonFinder.failPythonVersion (/Users/dotnsf/.nvm/versions/node/v8.9.4/lib/node_modules/npm/node_modules/node-gyp/lib/configure.js:492:19)
gyp ERR! stack     at PythonFinder. (/Users/dotnsf/.nvm/versions/node/v8.9.4/lib/node_modules/npm/node_modules/node-gyp/lib/configure.js:474:14)
gyp ERR! stack     at ChildProcess.exithandler (child_process.js:267:7)
gyp ERR! stack     at emitTwo (events.js:126:13)
gyp ERR! stack     at ChildProcess.emit (events.js:214:7)
      :
      :

スクリーンショット 2018-08-21 9.44.07


Node.js でネイティブモジュールのビルドが必要になった場合に node-gyp を使ってビルドが行われるのですが、その際に使われる Python のバージョンがあっていない、というエラーです。ちと厄介なのは Python のバージョンが古くて問題になっているのではなく、新しすぎてエラーが発生している、ということです(上の例では v2.5.0 以上 v3.0.0 未満でないといけないのに v3.6.5 がインストールされていてエラーが発生している、というメッセージが表示されています)。

この解決のためにわざわざ古いバージョンをインストールしないといけないのか、ということはなく、以下のようにバージョンを明示して npm install することで解決できます:
$ npm install canvas --python=python2.7

> canvas@1.6.11 install /Users/dotnsf/src/tmp/node_modules/canvas
> node-gyp rebuild

gyp WARN download NVM_NODEJS_ORG_MIRROR is deprecated and will be removed in node-gyp v4, please use NODEJS_ORG_MIRROR
      :
      :

+ canvas@1.6.11
added 2 packages in 10.027s


Node.js を使っていて 404 エラーや 500 エラーなどが発生した場合に表示されるエラーページをカスタマイズできないか、と思って挑戦してみました。

今回挑戦した環境では Node.js にフレームワークの Express と、テンプレートエンジンに EJS を使いました。エラーページを EJS で作ることを想定しています。

まず、JavaScript のコードはこんな感じです:

app.js
// app.js
var express = require( 'express' );
var app = express();

//. EJS テンプレートエンジン
app.set( 'views', __dirname + '/templates' );
app.set( 'view engine', 'ejs' );

//. / へのアクセスは正常にできる
app.get( '/', function( req, res ){
  res.render( 'index', {} );
});

//. /err へのアクセスは 500 エラーとする
app.get( '/err', function( req, res ){
  res.render( 'index', { value: novalue } ); //. novalue 変数が未定義なので 500 エラーが発生する
});

//. 有効なルーティングを上記に記述
//. /, /err 以外のパスは 404 エラー

//. 404 エラーが発生した場合、
app.use( function( req, res, next ){
  res.status( 404 ); //. 404 エラー
  res.render( 'err404', { path: req.path } ); //. 404 エラーが発生したパスをパラメータとして渡す
});

//. 500 エラーが発生した場合、
app.use( function( err, req, res, next ){
  res.status( 500 ); //. 500 エラー
  res.render( 'err500', { error: err } ); //. 500 エラーの内容をパラメータとして渡す
});

var port = 3000;
app.listen( port );
console.log( 'server started on ' + port );

上記を補足すると、Express でルーティングを2つ定義しています。1つめがドキュメントルート(/)へのアクセスで、この場合は正常な処理として(後述の)index.ejs を表示します。

2つめは /err へのアクセスで、こちらの場合はわざと 500 エラーを発生させています(index.ejs でページを表示させるような記述にしていますが、実際にはこの中で使われている novalue という変数が未定義なので、そこで 500 エラーが発生するようにしています)。

ルーティングとしてはこの2つ(/ と /err)だけを定義しているので、これら以外のパス(例えば /home)にアクセスがあった場合は 404 エラーが発生します。404 エラーが発生した場合の処理としては err404.ejs というテンプレートを使って、アクセスしたパス(/home)が存在していない、という旨のエラーページを表示します。

最後に 500 エラーが発生した場合の処理を定義しています。ここでは err500.ejs というテンプレートを使って、エラーの内容をあわせて表示します。上記で /err ページにアクセスすると 500 エラーが発生するので、この err500.ejs のページが表示されることになります。


次に上記で使うことにした3種類のテンプレート(index.ejs, err404.ejs, err500.ejs)を用意します。それぞれ以下のような内容にしました:

index.ejs
<html>
<head>
<title>index</title>
</head>
<body>
<h1>index</h1>
</body>
</html>
↑単に index と表示されるだけのシンプルなページ


err404.ejs
<html>
<head>
<title>err404</title>
</head>
<body>
<h1>err404</h1>
<%= path %> is not defined nor found.
</body>
</html>
↑ "(エラーがあったパス)is not defined nor found." というエラーメッセージが表示されるページ


err500.ejs
<html>
<head>
<title>err500</title>
</head>
<body>
<h1>err500</h1>
Error: <%= error %>
</body>
</html>
↑ "Error: (エラー内容)" というエラーメッセージが表示されるページ


app.js ではこれらのテンプレートファイルが templates/ フォルダに存在していることを前提に参照するようにしています。したがって templates/ フォルダを作って、その中にこれら3つの .ejs ファイルを格納しておきます。これで準備OK。


実際に動かして試してみました。まずは正常系、/ へのアクセスは普通に問題なくできます:
2018070401


次に /home にアクセスして、わざと 404 エラーを発生させてみた時の画面です。err404.ejs で定義されたテンプレートを使って期待通りにエラーページが表示されています:
2018070402


最後に /err にアクセスして、わざと 500 エラーを発生させてみた時の画面です。こちらも err500.ejs で定義されたテンプレートを使って期待通りにエラー内容が表示されています:
2018070403


上記コードのサンプルをこちらに用意しました:
https://github.com/dotnsf/nodejserror


これで Node.js でもカスタムエラーページを作れることがわかりました。

まだ同期/非同期処理の違いに戸惑いながら Node.js を使っています。で、先日こんな実行時エラーに遭遇しました:
  :
  :
events.js:141 throw er; // Unhandled 'error' event ^ Error: EMFILE: too many open files, open '/home/kkimura/XXX/images/*****.jpg` at Error (native)

その時のコード(抜粋)がこちらです:
var fs = require( 'fs' );
fs.readdir( './images', function( err, files ){  // ./images/ フォルダを開く
  if( err ) throw err;
  
  files.forEach( function( jpgfile ){  // ./images/ フォルダの全ファイルを1つずつ取り出して、、、
          :
    (各ファイルに対する処理)
          :
  });
});

現在のディレクトリから、fs モジュールを使って images/ サブフォルダの中にある画像ファイル全てを取り出して、各ファイルに対して何らかの処理をする・・・という、よくあるとまで言えるかどうかはわかりませんが、ごく普通の内容だと思います。この処理中に上記のエラーが発生しました。エラーそのものもネイティブコードの中で発生しているので、どの画像ファイルを読み込んでいる時のエラーかはわかるのですが、何が原因のエラーなのかのヒントはほとんどありませんでした(結論としては画像ファイル側の問題ではないので、どの画像ファイルであったかは解決の上ではあまり重要な情報ではありませんでした)。

が、エラーメッセージそのものから原因はなんとなく推測できました。

まず、この処理は特定のフォルダ(./images)の中にある全てのファイルを取り出し、forEach() ループで各ファイル毎になんらかの処理をする、というものです。そしてエラーメッセージは "Too many open files(ファイルを開きすぎている)"。 実際、このフォルダ内には非常に多くのファイルが存在していたのですが、それらを同時に開きすぎて、処理の限界を超えてしまった、というエラーが発生していたようです。

というわけで原因はなんとなくわかりました。しかし本当の問題はここから。


Node.js(JavaScript) は非同期に処理を実行します。つまり上記のようなケースでは「ファイルを1つずつ開いて処理をして、終わったら閉じて次へ」ではなく、「同時に(非同期に)全ファイルを開いて、同時に(非同期に)全ファイルに処理を施して・・・」という形で実行されます。そしてその際に多くのファイルを開きすぎて "Too many open files" というエラーが発生していたのでした。このエラーは多くのファイルが保管されているディレクトリへの処理を非同期に実行する以上は解決しにくい問題のように思えますが、さてどうする・・・


これ、自分以外でも悩んでいる人が多かったらしく、StackOverflow などでも議論(後述)されていました。結果的には fs ライブラリそのものを改良したものを使う、という方法が紹介されていました。その改良モジュール(graceful-fs)はこちら:
https://github.com/isaacs/node-graceful-fs

この graceful-fs は fs の代わりに使うことができ、かつ "Too many open files" エラー時に発生する EMFILE イベントを検知したら、少し待ってからやり直し処理を行う(という方法でエラーを回避しながら全ファイルを処理する)、という処理が実装されたもののようです。

graceful-fs モジュールを使うには、まず npm 等でインストールを行います:
$ npm install graceful-fs

そしてコードを書き換えます。といっても require( 'fs' ) を require( 'graceful-fs' ) にするだけで、他は変更なしでそのままエラーもなく動きました:
var fs = require( 'graceful-fs' );
fs.readdir( './images', function( err, files ){
  if( err ) throw err;
  
  files.forEach( function( jpgfile ){
          :
    (jpgfile に対する処理)
          :
  });
});


それにしても同期/非同期処理の頭を素早く切り替え出来るのって、それだけで才能ではないかと思う。。。


(参考)
http://stackoverflow.com/questions/8965606/node-and-error-emfile-too-many-open-files

とある REST API を使っていて気付いたこと/考えさせられたことをまとめてみました。明快な結論や提案があるわけではなく、グダグダに感じられる内容かもしれないので、あらかじめご了承ください。


そのとある REST API を使ったウェブアプリケーションを作って運用している中で、おかしな挙動に気付くことがありました。以前は問題なく動いていたのに、あるタイミングで実行すると期待通りに動かない、という「まあまあよくある」ケースです。自分のケースでは動かないというよりも、タイムアウトを起こすような挙動になっていました。ただ REST API そのものが止まっている様子はない、というケースでした。

自分のソースコードでは一応エラーハンドリングはしていたつもりでしたが、REST API がエラーを起こしている様子もなく、原因究明に時間を要するものでした。結論としては自分のアプリケーションコードを見ていてもよく分からず、REST API のユニットテストのようなツールを動かした結果気付くことがありました。

それがこちら:
20170207


・・・わかるでしょうか? REST API を実行したレスポンス本文が Response Body に、ステータスコードが Response Code に記述されています。これによるとレスポンス本文は
{
  "status": "ERROR",
  "statusInfo": "daily-transaction-limit-exceeded"
}

となっていて、"daily-transaction-limit-exceeded" が原因のエラーが発生している、という内容でした。この API には Daily Transaction Limit(1日で使える回数の上限)が決められていて、その上限に達したのでもう実行できない、という内容です。これに関してはそういう条件で使っている API なので、なるほど、エラーの原因はわかりました。

問題はこの REST API を実行したステータスコードが 200 になっている点です。HTTP ステータスコードの分類とその意味についてはウィキペディアなどを参照していただきたいのですが、簡単にいうとこんな感じで分類されています:
コード意味考えられる原因など
2xx(200番台)成功 -
4xx(400番台)クライアントエラー認証が必要、アクセス権がない、URLが間違っている、タイムアウト、、、
5xx(500番台)サーバーエラーアプリケーションエラー、不正なゲートウェイが利用されている、、、


200 番台は成功。400 番台と 500 番台がエラーで、それぞれクライアント側のエラーなのか、サーバー側のエラーなのかを分類しています。

で、今回のケースですが、実行結果はエラーなのに 200 番のステータスコードが返されているのでした。自分のプログラムコードの中では「200 が返ってきたら成功」と決めつけて実装していたため、このようなケースに対処できていなかったのでした。


ここまでが実際に目の当たりにしたエラーとその原因でした。以下はこの件に関して自分が考えたことです。


自分を弁護する意味で「えー、でもそれっておかしくない? エラーなんだからスタータスコードは 400 番台なり 500 番台で返ってくるべきでは?」という考えもないわけではありません。ただ今回のケースではこれも難しいような、つまり 200 番のステータスコードがあながち間違ってはいないような気もしています。

その理由として、まず「これはクライアントエラーなのか?それともサーバーエラーなのか?どちらかに分類できるのか?」という問題です。これに関してはどちらとも言えるし、どちらとも言えないと思っています。

実は 402 番のステータスコードは "Payment Required" 、つまり(お金を払わないといけないんだけど)払ってないエラー、と定義されています。が、実際には定義だけで実装されていない、つまり将来のための定義とされているのでした。また厳密には支払い契約を結んで使っているわけではなく、「この条件で1日○○回使える」というルールの下で利用しているだけなので、402 番に(クライアントエラーに)該当するエラーであるとは考えにくいのです。

※本来の意味とは違いますが、「権限がない」に該当するのではないかと言われると、まあ・・・ という考え方もあるとは思います。ただそれをクライアントエラーとして返してもクライアント側はどうにもできないので、やはり 400 番台エラーには該当しないと思います。

ではサーバーエラーなのか?というと、これも該当しないと思います。プログラミングにミスがあったわけではなく、「実行したら、『実行できない』という結果が返ってきた」のは、正しく実行された(結果が期待通りではなかった)とも言えます。そう考えると、そもそも今回の件は REST API レベルではエラーですらないとも言えます。


そう考えると、今のように API を組み合わせてアプリケーションを作ることが珍しくない環境においては、200 番のステータスコードが返ってきてもエラーの可能性を疑ってコーディングする必要があるのかも、と思うようになりました。このケースであれば実装側が工夫すれば(というか、そもそもちゃんと色んなケースを想定してエラーハンドリングしていれば)防げるものです。

そういう意味でもいい反省の機会でした。 でも今後は同様のケースを想定した「成功でもエラーでもないステータス」が出て来る可能性もありますよね。。


このページのトップヘ