QA@IT

Rails4のdevelopment環境で 503 Service Temporarily Unavailable が発生します

1589 PV

Rails4のdevelopment環境で 503 Service Temporarily Unavailable が発生します。

  1. Webから画像(複数枚)をDLして、
  2. その画像をRMagickで加工して、
  3. 加工した画像をDB(sqlite)に保存して、
  4. またその画像をDBからSelectしてHTMLに表示する

という処理を行っている箇所で発生しているようなので、DBに負荷がかかったり、
あるいはサーバに負荷がかかったりしているだろうと予測はできるのですが、
ログなどからエラーが発生した原因を切り分けるにはどうしたら良いでしょうか?

ちなみにdevelopment環境用のサーバにはunicornを使っています。

DBアクセスの直後に
Completed 500 Internal Server Error in 3262ms
とlog出力されているので、DBでエラー(タイムアウトとか)が発生しているのかなと思ったのですが、
sqlite3のlogってどこかに出力されているのでしょうか?

以下、development.logのエラーが発生した部分を貼っておきます。よろしくお願いします。

Started POST "/dashboard/subscribe" for 127.0.0.1 at 2014-03-26 20:25:44 +0900
Processing by DashboardController#subscribe as HTML
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"b285+t9eeQ7M6QCuIie7tWpzad4JF2NitClL05Gsf5Y=", "site_url"=>"http://blog.livedoor.jp/dankogai/", "commit"=>"購読する"}
  [1m[36mWebSite Load (0.2ms)[0m  [1mSELECT "web_sites".* FROM "web_sites" WHERE "web_sites"."feed_url" = 'http://blog.livedoor.jp/dankogai/index.rdf' LIMIT 1[0m
  [1m[35m (0.1ms)[0m  begin transaction
  [1m[36mSQL (0.4ms)[0m  [1mINSERT INTO "web_sites" ("created_at", "feed_url", "name", "site_url", "updated_at") VALUES (?, ?, ?, ?, ?)[0m  [["created_at", Wed, 26 Mar 2014 11:25:45 UTC +00:00], ["feed_url", "http://blog.livedoor.jp/dankogai/index.rdf"], ["name", "404 Blog Not Found"], ["site_url", "http://blog.livedoor.jp/dankogai/"], ["updated_at", Wed, 26 Mar 2014 11:25:45 UTC +00:00]]
  [1m[35m (8.9ms)[0m  commit transaction
  [1m[36mArticle Load (0.2ms)[0m  [1mSELECT "articles".* FROM "articles" WHERE "articles"."url" = 'http://blog.livedoor.jp/dankogai/archives/51913215.html' LIMIT 1[0m
  [1m[35m (0.1ms)[0m  begin transaction
  [1m[36mSQL (0.5ms)[0m  [1mINSERT INTO "articles" ("created_at", "description", "published_at", "thumbnail", "title", "updated_at", "url", "web_site_id") VALUES (?, ?, ?, ?, ?, ?, ?, ?)[0m  [["created_at", Wed, 26 Mar 2014 11:25:45 UTC +00:00], ["description", "Unixという考えかたMikeGancarz/芳尾桂訳[原著:TheUnixPhilosophy]寝込みうどんになりながらiPadで以下を読んだら熱がぶりかえしたので。Macの良さがわからなすぎて、死"], ["published_at", Mon, 24 Mar 2014 23:00:14 UTC +00:00], ["thumbnail", "<14728 bytes of binary data>"], ["title", "Windowsという名の薄皮一枚"], ["updated_at", Wed, 26 Mar 2014 11:25:45 UTC +00:00], ["url", "http://blog.livedoor.jp/dankogai/archives/51913215.html"], ["web_site_id", 2]]
  [1m[35m (9.2ms)[0m  commit transaction
  [1m[36mArticle Load (0.2ms)[0m  [1mSELECT "articles".* FROM "articles" WHERE "articles"."url" = 'http://blog.livedoor.jp/dankogai/archives/51911918.html' LIMIT 1[0m
  [1m[35m (0.1ms)[0m  begin transaction
  [1m[36mSQL (0.5ms)[0m  [1mINSERT INTO "articles" ("created_at", "description", "published_at", "thumbnail", "title", "updated_at", "url", "web_site_id") VALUES (?, ?, ?, ?, ?, ?, ?, ?)[0m  [["created_at", Wed, 26 Mar 2014 11:25:46 UTC +00:00], ["description", "Webを支える技術HTTP、URI、HTML、そしてREST山本陽平であればなおのことこの実装はNG。ブラウザのキャッシュを利用できれば、余分なリクエストを減らすことができます。はてなブログでは、なる"], ["published_at", Fri, 14 Mar 2014 20:00:15 UTC +00:00], ["thumbnail", "<14365 bytes of binary data>"], ["title", "Tips - 静的リソースのURIに?をつけるべからず"], ["updated_at", Wed, 26 Mar 2014 11:25:46 UTC +00:00], ["url", "http://blog.livedoor.jp/dankogai/archives/51911918.html"], ["web_site_id", 2]]
  [1m[35m (8.4ms)[0m  commit transaction
  [1m[36mArticle Load (0.2ms)[0m  [1mSELECT "articles".* FROM "articles" WHERE "articles"."url" = 'http://blog.livedoor.jp/dankogai/archives/51911784.html' LIMIT 1[0m
  [1m[35m (0.1ms)[0m  begin transaction
  [1m[36mSQL (0.5ms)[0m  [1mINSERT INTO "articles" ("created_at", "description", "published_at", "thumbnail", "title", "updated_at", "url", "web_site_id") VALUES (?, ?, ?, ?, ?, ?, ?, ?)[0m  [["created_at", Wed, 26 Mar 2014 11:25:46 UTC +00:00], ["description", "USJのジェットコースターはなぜ後ろ向きに走ったのか?森岡毅たとえ話を一つ。些末なコードレビュー-naoyaのはてなダイアリーあるサービスのJavaScriptが重いとか、そのコードが難読化されてない"], ["published_at", Thu, 13 Mar 2014 16:30:59 UTC +00:00], ["thumbnail", "<13405 bytes of binary data>"], ["title", "些末なゴミは出所を問わず拾うのが客商売"], ["updated_at", Wed, 26 Mar 2014 11:25:46 UTC +00:00], ["url", "http://blog.livedoor.jp/dankogai/archives/51911784.html"], ["web_site_id", 2]]
  [1m[35m (1.1ms)[0m  commit transaction
  [1m[36mArticle Load (0.2ms)[0m  [1mSELECT "articles".* FROM "articles" WHERE "articles"."url" = 'http://blog.livedoor.jp/dankogai/archives/51910930.html' LIMIT 1[0m
  [1m[35m (0.1ms)[0m  begin transaction
  [1m[36mSQL (0.5ms)[0m  [1mINSERT INTO "articles" ("created_at", "description", "published_at", "thumbnail", "title", "updated_at", "url", "web_site_id") VALUES (?, ?, ?, ?, ?, ?, ?, ?)[0m  [["created_at", Wed, 26 Mar 2014 11:25:46 UTC +00:00], ["description", "サーバサイドJavaScriptNode.js入門OSバージョンを上げたついでに、llevalにも手を入れたので変更点など。lleval-runcodesfromyourbrowser"], ["published_at", Thu, 06 Mar 2014 18:00:49 UTC +00:00], ["thumbnail", "<19085 bytes of binary data>"], ["title", "llevalに久しぶりに手を入れた"], ["updated_at", Wed, 26 Mar 2014 11:25:46 UTC +00:00], ["url", "http://blog.livedoor.jp/dankogai/archives/51910930.html"], ["web_site_id", 2]]
  [1m[35m (8.1ms)[0m  commit transaction
  [1m[36mArticle Load (0.3ms)[0m  [1mSELECT "articles".* FROM "articles" WHERE "articles"."url" = 'http://blog.livedoor.jp/dankogai/archives/51910175.html' LIMIT 1[0m
  [1m[35m (0.1ms)[0m  begin transaction
  [1m[36mSQL (0.4ms)[0m  [1mINSERT INTO "articles" ("created_at", "description", "published_at", "title", "updated_at", "url", "web_site_id") VALUES (?, ?, ?, ?, ?, ?, ?)[0m  [["created_at", Wed, 26 Mar 2014 11:25:46 UTC +00:00], ["description", "404SPAMNotFound#20核心の問題http://t.co/XeKvafeowL#blomaga—DanKogai(@dankogai)February28,2014"], ["published_at", Fri, 28 Feb 2014 21:00:20 UTC +00:00], ["title", "ブロマガ更新 - 404 SPAM Not Found #20 核心の問題"], ["updated_at", Wed, 26 Mar 2014 11:25:46 UTC +00:00], ["url", "http://blog.livedoor.jp/dankogai/archives/51910175.html"], ["web_site_id", 2]]
  [1m[35m (0.8ms)[0m  commit transaction
  [1m[36mArticle Load (0.2ms)[0m  [1mSELECT "articles".* FROM "articles" WHERE "articles"."url" = 'http://blog.livedoor.jp/dankogai/archives/51909226.html' LIMIT 1[0m
  [1m[35m (0.1ms)[0m  begin transaction
  [1m[36mSQL (0.6ms)[0m  [1mINSERT INTO "articles" ("created_at", "description", "published_at", "thumbnail", "title", "updated_at", "url", "web_site_id") VALUES (?, ?, ?, ?, ?, ?, ?, ?)[0m  [["created_at", Wed, 26 Mar 2014 11:25:47 UTC +00:00], ["description", "図解・内臓の進化岩堀修明オビを書いたのでここでも紹介。"], ["published_at", Fri, 21 Feb 2014 16:30:35 UTC +00:00], ["thumbnail", "<17180 bytes of binary data>"], ["title", "A Brief History of Guts - 紹介 - 図解・内臓の進化"], ["updated_at", Wed, 26 Mar 2014 11:25:47 UTC +00:00], ["url", "http://blog.livedoor.jp/dankogai/archives/51909226.html"], ["web_site_id", 2]]
  [1m[35m (0.9ms)[0m  commit transaction
  [1m[36mArticle Load (0.2ms)[0m  [1mSELECT "articles".* FROM "articles" WHERE "articles"."url" = 'http://blog.livedoor.jp/dankogai/archives/51907188.html' LIMIT 1[0m
  [1m[35m (0.1ms)[0m  begin transaction
  [1m[36mSQL (0.5ms)[0m  [1mINSERT INTO "articles" ("created_at", "description", "published_at", "thumbnail", "title", "updated_at", "url", "web_site_id") VALUES (?, ?, ?, ?, ?, ?, ?, ?)[0m  [["created_at", Wed, 26 Mar 2014 11:25:47 UTC +00:00], ["description", "この後無茶苦茶インストールしまくった。FreeBSD10.0-RELEASEAnnouncementので、気づいたことを。"], ["published_at", Wed, 05 Feb 2014 18:45:27 UTC +00:00], ["thumbnail", "<2191 bytes of binary data>"], ["title", "備忘録 - FreeBSD 10 あれこれ"], ["updated_at", Wed, 26 Mar 2014 11:25:47 UTC +00:00], ["url", "http://blog.livedoor.jp/dankogai/archives/51907188.html"], ["web_site_id", 2]]
  [1m[35m (0.8ms)[0m  commit transaction
  [1m[36mArticle Load (0.2ms)[0m  [1mSELECT "articles".* FROM "articles" WHERE "articles"."url" = 'http://blog.livedoor.jp/dankogai/archives/51906737.html' LIMIT 1[0m
  [1m[35m (0.1ms)[0m  begin transaction
  [1m[36mSQL (0.5ms)[0m  [1mINSERT INTO "articles" ("created_at", "description", "published_at", "thumbnail", "title", "updated_at", "url", "web_site_id") VALUES (?, ?, ?, ?, ?, ?, ?, ?)[0m  [["created_at", Wed, 26 Mar 2014 11:25:47 UTC +00:00], ["description", "初めてのPerl第6版RandalL.Schwartz/TomPhoenix/briandfoy/近藤嘉雪訳[原著:LearningPerl,6thed.]久々のPerlの話題です。"], ["published_at", Sun, 02 Feb 2014 17:15:32 UTC +00:00], ["thumbnail", "<15735 bytes of binary data>"], ["title", "perl - func(tion()) considered harmful?"], ["updated_at", Wed, 26 Mar 2014 11:25:47 UTC +00:00], ["url", "http://blog.livedoor.jp/dankogai/archives/51906737.html"], ["web_site_id", 2]]
  [1m[35m (9.1ms)[0m  commit transaction
  [1m[36mArticle Load (0.3ms)[0m  [1mSELECT "articles".* FROM "articles" WHERE "articles"."url" = 'http://blog.livedoor.jp/dankogai/archives/51906488.html' LIMIT 1[0m
  [1m[35m (0.1ms)[0m  begin transaction
  [1m[36mSQL (0.4ms)[0m  [1mINSERT INTO "articles" ("created_at", "description", "published_at", "title", "updated_at", "url", "web_site_id") VALUES (?, ?, ?, ?, ?, ?, ?)[0m  [["created_at", Wed, 26 Mar 2014 11:25:47 UTC +00:00], ["description", "404SPAMNotFound#19俺の幹細胞がそんなにちょろいなわけがないhttp://t.co/LpdFi48DgQ#blomaga—DanKogai(@dankogai)January31,20"], ["published_at", Fri, 31 Jan 2014 15:00:50 UTC +00:00], ["title", "ブロマガ更新 - 404 SPAM Not Found #19 俺の幹細胞がそんなにちょろいなわけがない"], ["updated_at", Wed, 26 Mar 2014 11:25:47 UTC +00:00], ["url", "http://blog.livedoor.jp/dankogai/archives/51906488.html"], ["web_site_id", 2]]
  [1m[35m (0.7ms)[0m  commit transaction
  [1m[36mArticle Load (0.2ms)[0m  [1mSELECT "articles".* FROM "articles" WHERE "articles"."url" = 'http://blog.livedoor.jp/dankogai/archives/51906277.html' LIMIT 1[0m
Completed 500 Internal Server Error in 3262ms

OpenURI::HTTPError (503 Service Temporarily Unavailable):
  app/models/article.rb:60:in `to_thumbnail'
  app/models/article.rb:18:in `block (2 levels) in create_by_web_site'
  app/models/article.rb:12:in `block in create_by_web_site'
  app/models/article.rb:11:in `each'
  app/models/article.rb:11:in `create_by_web_site'
  app/models/web_site.rb:12:in `create_articles'
  app/models/web_site.rb:29:in `find_or_create_by_url'
  app/controllers/dashboard_controller.rb:15:in `subscribe'


  Rendered vendor/bundle/ruby/2.0.0/gems/actionpack-4.0.2/lib/action_dispatch/middleware/templates/rescues/_source.erb (0.5ms)
  Rendered vendor/bundle/ruby/2.0.0/gems/actionpack-4.0.2/lib/action_dispatch/middleware/templates/rescues/_trace.erb (1.0ms)
  Rendered vendor/bundle/ruby/2.0.0/gems/actionpack-4.0.2/lib/action_dispatch/middleware/templates/rescues/_request_and_response.erb (0.9ms)
  Rendered vendor/bundle/ruby/2.0.0/gems/actionpack-4.0.2/lib/action_dispatch/middleware/templates/rescues/diagnostics.erb within rescues/layout (12.7ms)
  • 回答者が退会されたようなので -1 -

回答

スタックトレース見ると

OpenURI::HTTPError (503 Service Temporarily Unavailable):

と出力されているので、Webから画像をDLするのに失敗しているのではないでしょうか。

編集 履歴 (0)
ウォッチ

この質問への回答やコメントをメールでお知らせします。