6/18にdotCloudが「New Pricing + Unlimited Service」と題したバージョンアップをして、今まで2つまでだったアプリ作成可能数が無制限になったりしました。
が、6/18以前から起動していた既存Node.jsアプリをデプロイしなおしただけなのに動かなくなる現象に見舞われました。なんとか対処できたのでメモを残します。

症状

  • デプロイ時のコンソールログはいつもと変わらず
  • が、ブラウザでアクセスすると、ステータス502
  • 画面には“Cannot find valid backend. “ と出る

調査

アプリケーション名=wstest

statusを見る

$ dotcloud run wstest.www supervisorctl status
# supervisorctl status
node                             FATAL      Exited too quickly (process log may have details)

FATALになっており、起動できていない。

ログを見る

$ dotcloud logs wstest.www
#  tail -F /var/log/supervisor/*.log
> /var/log/supervisor/node-stderr---supervisor-_4f8Ms.log <
    at Function._resolveFilename (module.js:317:11)
    at Function._load (module.js:262:25)
    at require (module.js:346:19)
    at Object.<anonymous> (/home/dotcloud/node_modules/express/node_modules/connect/lib/middleware/compress.js:14:12)
    at Module._compile (module.js:402:26)
    at Object..js (module.js:408:10)
    at Module.load (module.js:334:31)
    at Function._load (module.js:293:12)
    at require (module.js:346:19)
    at Object.compress (/home/dotcloud/node_modules/express/node_modules/connect/lib/connect.js:89:14)
 
> /var/log/supervisor/node-stdout---supervisor-dLyD6H.log <
 
> /var/log/supervisor/supervisord.log <
2012-06-20 04:39:27,044 INFO supervisord started with pid 140
2012-06-20 04:39:28,051 INFO spawned: 'node' with pid 147
2012-06-20 04:39:28,228 INFO exited: node (exit status 1; not expected)
2012-06-20 04:39:29,234 INFO spawned: 'node' with pid 156
2012-06-20 04:39:29,406 INFO exited: node (exit status 1; not expected)
2012-06-20 04:39:31,414 INFO spawned: 'node' with pid 157
2012-06-20 04:39:31,595 INFO exited: node (exit status 1; not expected)
2012-06-20 04:39:34,604 INFO spawned: 'node' with pid 158
2012-06-20 04:39:34,772 INFO exited: node (exit status 1; not expected)
2012-06-20 04:39:35,773 INFO gave up: node entered FATAL state, too many start retries too quickly

expressが依存しているconnectというライブラリのlib/middleware/compress.jsというところでエラーが発生しているらしい。

さらに調査

うまく動いているローカル環境と見比べたところ、ローカル環境にはlib/middleware/compress.jsはなかった。
ならばconnectのバージョンが怪しいと思い調べると、

ローカル1.8.7
dotCloud1.9.0

であった。
(dotCloud側のライブラリのバージョンは、デプロイ時のコンソールログに出てる)

対応

connectのバージョンを合わせるために、package.jsonにconnectの1.8.7を指定

:
  "dependencies": {
    "express": "2.5.9",
    "connect": "1.8.7", //←追加
    "ejs": "0.7.1",
    "socket.io": "0.9.5",
    "i18n": "0.3.0"
  },
:

再度デプロイ

$ dotcloud push wstest .
:
(中略)
:
04:45:19 [www] ejs@0.7.1 ./node_modules/ejs
04:45:19 [www] i18n@0.3.0 ./node_modules/i18n
04:45:19 [www] └── sprintf@0.1.1
04:45:19 [www] express@2.5.9 ./node_modules/express
04:45:19 [www] ├── qs@0.4.2
04:45:19 [www] ├── mkdirp@0.3.0
04:45:19 [www] └── mime@1.2.4
04:45:19 [www] connect@1.8.7 ./node_modules/connect ←1.8.7が入った
04:45:19 [www] ├── formidable@1.0.11
04:45:19 [www] ├── mime@1.2.5
04:45:19 [www] └── qs@0.5.0
04:45:19 [www] socket.io@0.9.5 ./node_modules/socket.io
04:45:19 [www] ├── policyfile@0.0.4
04:45:19 [www] ├── redis@0.6.7
04:45:19 [www] └── socket.io-client@0.9.5
04:45:29 ---> Application build is done
:
(中略)
:
www: http://textrans.roundrop.jp/

うまいことconnect1.8.7が入ったっぽい。

起動確認

$ dotcloud run wstest.www supervisorctl status
# supervisorctl status
node                             RUNNING    pid 147, uptime 0:00:11

RUNNING!動いた!