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

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

タグ:status

HTTP プロトコルを使っていると、「HTTP ステータスコード(以下、「ステータスコード」)」を意識することがあります:
http-status-codes


ステータスコードは HTTP リクエストを実行した結果を端的に表す3桁の数字です。最も有名かつ一般的なステータスコードは 200 で "OK" の意、つまり「リクエストが成功した場合のステータスコード」(「HTTP リクエストが成功すると 200 というステータスコードが返ってくる」と理解するとわかりやすいかも)です。

200 以外だと 404("Not Found" URL やファイルが存在しない場合など)や 403("Forbidden" アクセス権限がない場合など)あたりが比較的多く目にする機会があるものでしょうか。まあ本来あってはならない 500("Internal Server Error" サーバー内部エラー)とかもたまに見ることありますけど。。 なお規格として定義されているステータスコードの一覧はこちらを参照してください:
https://developer.mozilla.org/en-US/docs/Web/HTTP/Status


ともあれ、特にアプリケーションを開発したり運用したりしていると、「必ずしも 200 のステータスコードばかりが返ってくるわけではない」ことを意識する必要に迫られることがあります。なんらかの原因でエラーが発生してしまうことはあるし、どういうエラーとなった場合にどのような挙動にするのか、ということまで考慮して開発・運用する必要がある、という意味です。


一方でそこまで意識していたとしても、開発した/運用中のアプリケーションがエラーに遭遇するのは稀なケースのはずです。「こういうエラーの時はこういう挙動にする」ための準備をしていても、思いのままに任意のエラーを出せるわけではないのです。


そんなケースを想定して、「任意の HTTP ステータスコードを返す」アプリを作ってみました。URL パラメータに返してほしいステータスコードを指定して GET リクエストを送ると、レスポンスは指定したステータスコードが返ってくる※、というものです。

※本来のあるべき挙動とは異なります。要はアプリケーションとしては正しく動いている(ステータスコードは 200 になるべき)にも関わらず、本来返すべきステータスコードとは異なる 404 等を返す、という挙動をします。あくまで上述のようなケースのデバッグ用および動作確認用アプリケーションです。


アプリケーションのソースコードはこちらで公開しています:
https://github.com/dotnsf/statuscode_generator

また Docker イメージもこちらから取得可能です:
https://hub.docker.com/r/dotnsf/statuscode_generator


ローカルの Docker エンジンを使って動かす場合は、以下のように指定して実行します(8080 番ポートでアクセス可能にする場合):
$ docker run -d --name statuscode-generator -p 8080:8080 dotnsf/statuscode-generator

起動しているアプリケーションに GET /status リクエストを実行します。URL パラメータ code を付けて実行すると、指定したステータスコードが返されます(デフォルトは 200):
$ curl -v http://localhost:8080/status

*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 8080 (#0)
> GET /status HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.58.0
> Accept: */*
>
< HTTP/1.1 200 OK
< X-Powered-By: Express
< Content-Type: application/json; charset=utf-8
< Date: Sun, 24 Oct 2021 05:32:20 GMT
< Connection: keep-alive
< Keep-Alive: timeout=5
< Transfer-Encoding: chunked
<
{
  "code": 200,
  "reference_url": "https://developer.mozilla.org/en-US/docs/Web/HTTP/Status",
  "timestamp": 1635053540644
* Connection #0 to host localhost left intact

$ curl -v http://localhost:8080/status?code=404

*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 8080 (#0)
> GET /status?code=404 HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.58.0
> Accept: */*
>
< HTTP/1.1 404 Not Found
< X-Powered-By: Express
< Content-Type: application/json; charset=utf-8
< Date: Sun, 24 Oct 2021 05:33:03 GMT
< Connection: keep-alive
< Keep-Alive: timeout=5
< Transfer-Encoding: chunked
<
{
  "code": 404,
  "reference_url": "https://developer.mozilla.org/en-US/docs/Web/HTTP/Status",
  "timestamp": 1635053583162
* Connection #0 to host localhost left intact

なお、起動時に環境変数 ALLOW_CORS が設定されていると、指定した値のサーバーからであれば CORS リクエストを受け付けるようになります(デフォルトでは CORS 無効):
(例 全てのサーバーからの CORS リクエストを受け付ける場合)
$ docker run -d --name statuscode-generator -e ALLOW_CORS=* -p 8080:8080 dotnsf/statuscode-generator

この ALLOW_CORS=* が指定された状態で起動しているサーバーを heroku 上に用意しておきました。heroku 無料枠で動かしているので初回アクセス時は(停止状態から起動するまで)少し時間がかかると思いますが、よかったらお使いください:
https://statuscode-generator.herokuapp.com/


なお、この任意のステータスコードを返す API は GET /status で直接実行できますが、(上述の heroku アプリのように) GET / でアクセスすると簡易 UI が現れ、簡単な動作確認ができます。返してほしいステータスコードを指定して AJAX ボタンをクリックすると、AJAX で GET /status?code=(指定したステータスコード) が実行され、その結果が画面下部に表示されます(下図は 403 を指定して実行した時の例):
2021102401


特にクラウドやコンテナ環境などで、アプリケーション・サーバーとは別にエッジサーバーがあってリバースプロクシーを使っている場合などリバースプロクシー側の動作設定をする場合に便利かと思い作ってみました(アプリケーションサーバーエラーが起こった場合はエッジサーバー側で特定のエラーページに遷移させる、といった設定をしている場合の動作確認時など)。自分以外にこれが役立つ人がどのくらいいるかわからないのですが、よかったら使ってください。役立つことがあれば嬉しいです。

なお、ステータスコードとして 1xx(百番台)を指定した場合ですが、HTTP ステータスコードとしては指定したものが返されます。が、1xx は実行途中の経過を返すものだったりして、実際の挙動という点ではこの続きがないと不自然な挙動となります。そのあたりまで考慮されているわけではない点をご了承ください。






とある 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 番のステータスコードが返ってきてもエラーの可能性を疑ってコーディングする必要があるのかも、と思うようになりました。このケースであれば実装側が工夫すれば(というか、そもそもちゃんと色んなケースを想定してエラーハンドリングしていれば)防げるものです。

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


IBM Bluemix を使ってアプリ開発を行い、「期待していた通りに動かない・・・ (--;」ということは普通にあると思っています。 そんな時のトラブルシューティングについて、大きく3つの原因パターンに分けて紹介します。


ケースその1 Bluemix 側に問題が発生している
 
何よりもまず最初に調べる必要なのがこれです。Bluemix 側に原因があってうまくいかないのか、自分のコードやアクションに問題があるのか、という切り分けです。

Bluemix のランタイムやサービスが正しく稼働していない場合(あるいはメンテナンス中の場合)、その機能を使ったアプリは当然うまく動かなくなります。そのため、まずは Bluemix の稼働ステータスを確認してください:
https://status.ng.bluemix.net/
2015120104


↑このサイトでデータセンターリージョン毎/ランタイム・サービス毎の稼働状態を確認することができます(近い将来のメンテナンス情報もわかります):
2015120105


おおまかにはこのサイトの情報で充分だと思いますが、認証機能などの内部的な機能レベルでの稼動状態を調べるにはこちらを参照ください:
http://estado.ng.bluemix.net/
2015120107


IBM DevOps Services などの外部サービスを併用して使っている場合は、それらの併用サービスについても確認が必要になります。例えば IBM DevOps Services の稼動状態はこちらで確認できます:
http://status.hub.jazz.net/
2015120106


これら上記4つの URL はブックマークしておくことをおすすめします。


ケースその2 プッシュ(デプロイ)できない

Bluemix 側に特に異常がないにもかかわらず、自分の作ったアプリケーションコードのプッシュ(デプロイ)に失敗する場合は、コードや設定ファイルの内容そのものに間違いが含まれている可能性を疑う必要があります。

例えば cf ツールを使って push したらこんな感じでエラーが発生することがあります:
> cf push appname1
Updating app appname1 in org dotnsf@jp.ibm.com / space dev as dotnsf@jp.ibm.com...
OK

Uploading appname1...
Uploading app files from: C:\tmp\appname1
Uploading 15.9K, 13 files
Done uploading
OK

Stopping app appname1 in org dotnsf@jp.ibm.com / space dev as dotnsf@jp.ibm.com...
OK

Starting app appname1 in org dotnsf@jp.ibm.com / space dev as dotnsf@jp.ibm.com...
-----> Downloaded app package (12K)
-----> Downloaded app buildpack cache (3.9M)


-------> Buildpack version 4.1.5


Traceback (most recent call last):
     :
     :
(中略)
: : ValueError: Expecting object: line 1 column 1 (char 0) Staging failed: Buildpack compilation step failed FAILED BuildpackCompileFailed TIP: use 'cf logs appname1 --recent' for more information

エラーが出てプッシュが FAILED になってしまいました。さてどうしましょう?

このようなケースではプッシュ時のログを参照するのがいいです。その方法は上記の最後に書かれているように、cf logs コマンドに "--recent" オプションを付けて実行することで(直近のログを)確認できます:
> cf logs appname1 --recent
      :
      :
      :
2015-12-01T09:53:08.75+0900 [STG/0]      OUT Downloaded [file:///var/vcap/data/d
ea_next/admin_buildpacks/ee88f28c-4afb-47c3-bc0f-db9ddc1ebb1d_6cbec4f53c789b674b
c4f011895cfb0f72c4d3e0/dependencies/https___pivotal-buildpacks.s3.amazonaws.com_
php_binaries_trusty_composer_1.0.0-alpha10_composer.phar] to [/tmp]
2015-12-01T09:53:08.76+0900 [STG/0]      OUT PROTIP: Include a `composer.lock` file with your application! This will make sure the exact same version of dependencies are used when you deploy to CloudFoundry.
2015-12-01T09:53:08.90+0900 [STG/0]      ERR Loading composer repositories with package information
2015-12-01T09:53:09.51+0900 [STG/0]      ERR Installing dependencies
2015-12-01T09:53:15.05+0900 [STG/0]      ERR Nothing to install or update
2015-12-01T09:53:15.05+0900 [STG/0]      ERR Generating autoload files
      :
      :
      :

この例だと composer の処理の中でエラーが発生しているようなメッセージが出力されていました。とすると、composer.json に間違いがあったのかな・・・と思って実際の composer.json ファイルを確認したらこんな内容でした:
{

閉じなければいけない大カッコが閉じられていませんでした。ケアレスミス! これが原因ですね。最後に "}" を追加してプッシュし直した所、エラーはなくなりました。これはあくまで一例ですが、プッシュ時のエラーに対してはプッシュ時のログを確認する、という対応が解決への近道になります。


ケースその3 プッシュしたアプリが正しく動かない

アプリケーションのプッシュ(デプロイ)には成功して、つまり Bluemix 上でアプリケーションが動いている状態になっていて、その上でアプリケーションが期待していたように動かない、ということがあります。コーディング内容と状態にもよりますが、画面にエラーが表示されたり、されなかったりします。

こんな時は(Bluemix 環境だけのトラブルシューティングではありませんが)稼働中のアプリケーションのログを見るのが第一です。Bluemix の場合はダッシュボードの「ログ」を選択すると、アプリケーションの全ログを参照することができます:
2015120101


ログが大量に出力されている場合はその TYPE や CHANNEL(標準出力/標準エラー)ごとに選別して絞り込むこともできます:
2015120102


この例であれば、明らかな PHP エラーが出力されていることがわかるような行がありました。これをヒントに該当のソースコードを見なおして、何が原因だったのか?を推測して修正する、ということが可能になります:
2015120103


この例の場合であれば up.php の 5 ~ 8 行目でまとめてエラーが出ていた、ということがわかります。ソースコードのこの辺りに原因が・・・という推測ができるわけです。後はソースコードを見て判断、ということになりますね。


以上をまとめると、Bluemix アプリケーション開発時のトラブルシューティングとしては以下のようになります:
1. Bluemix 側の異常ではないかを切り分け
2. プッシュ時のエラーはプッシュログを確認
3. プッシュ成功後のアプリケーション稼働時の問題はアプリケーションログを確認




 

このページのトップヘ