RoRで指定時間が過ぎたのに処理が行われなかった対応メモ。

Posted on 2013-03-15

しばらくRuby触ってなかったので焦りました。

というか１年以上誰も気づいていなかったバグ。

意外と見落としがち対応メモ。

現象

お知らせ表示開始時刻を過ぎてもお知らせのタイトル2が表示されない場合がある。

リロードすると表示されることもある。

タイトル1に関しては常に表示されている。

環境

OS: CentOS release 5.5 (Final)
LB: 不明
Web Server: Apache/2.2.3
- 4台
DB: Ver 14.12 Distrib 5.0.77, for redhat-linux-gnu (x86_64) using readline 5.1
- Master 1台
- Slave 2台
Ruby: 1.8.7
Ruby on Rails: 3.2.6

ソースとデータ

app/models/info.rb

class Info < ActiveRecord::Base
  # 公開中のものを取得
  scope :active, where(["start_date <= :time AND end_date >= :time", {:time => Time.now}])
end

app/controllers/info_controller.rb

class InfoController < ApplicationController
  def index
    # 公開中のお知らせ取得
    @infos = Info.active.page(params[:page])
  end
end

app/views/info/index.html.erb

<ul>
  <% @infos.each do|info| %>
    <li><%= info.title %></li>
  <% end %>
</ul>

info テーブルのデータ

id	title	start_date	end_date
1	タイトル1	2013-03-14 00:00:00	2013-03-10 00:00:00
2	タイトル2	2013-03-15 00:00:00	2013-03-31 00:00:00

原因

調査の結果、Webサーバ A、B、C、Dの4台のうちA、B、Dは正常に表示されているが、Webサーバ(C)のみタイトル2が表示されてないことがわかった。

本番のproduction環境の場合、Modelは一度しか読み込まれない。

その際、Model内にTime.nowなどの記述があると、その読み込み時刻が反映される。

つまり、今回のソースの場合、socpeで利用しているTime.now、:timeの値が次回サーバ再起動時まで固定となってしまうため、読み込みのタイミングが悪かったWebサーバ(C)のみ表示されないという事象が発生した。

ちなみに、development環境下の場合、都度読み込みになるので今回のバグは発生しないようです。

対応内容

下記のスライド内のCase2を参考に修正した。

実録！Railsのはまりポイント10選

lambdaで渡せばいいとのこと。

app/models/info.rb

class Info < ActiveRecord::Base
  # 公開中のものを取得
  scope :active, lambda{where(["start_date <= :time AND end_date >= :time", {:time => Time.now}]) }
end

無事表示できるようになりました。

当時のログを見直すと同じ修正を他のところでしてたみたいなので、その時の対応漏れっぽい。

これを機に他のソースも見なおしてみます。

以上です。

Ruby on Rails 5アプリケーションプログラミング

posted with ヨメレバ

山田祥寛技術評論社 2017-04-14

現象

環境

ソース と データ

原因

対応内容

ソースとデータ