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

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

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

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

現象

お知らせ表示開始時刻を過ぎてもお知らせのタイトル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
1
2
3
4
class Info < ActiveRecord::Base
# 公開中のものを取得
scope :active, where(["start_date <= :time AND end_date >= :time", {:time => Time.now}])
end
app/controllers/info_controller.rb
1
2
3
4
5
6
class InfoController < ApplicationController
def index
# 公開中のお知らせ取得
@infos = Info.active.page(params[:page])
end
end
app/views/info/index.html.erb
1
2
3
4
5
<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
1
2
3
4
class Info < ActiveRecord::Base
# 公開中のものを取得
scope :active, lambda{where(["start_date <= :time AND end_date >= :time", {:time => Time.now}]) }
end

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

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

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

以上です。

© 2018 磁力式駆動 All Rights Reserved.
Theme by hiero