環境

rails 5.1.4
ruby 2.5.0
mysql 5.7.20

背景

Railsでモデルを作っている時に時間に依存するバリデーションをかける必要がありました。

具体的には、とあるモデルのカラムにdatetime型でデータを保存し、update時に、そのカラムのDBの値と保存しようとしている値が異なる場合は、エラーをあげるというバリデーションをかけようとしていました。

つまり時刻を記録するためのカラムのため、誤って上書きがされないようにしたいということですね。その際に最初は、下記のようにRspecでテストを書いていたのですが、落ちてしまいました。

describe 'validations' do
  subject { hoge.update!(store_time: Time.zone.now) }
  let(:hoge) { create(:hoge, store_time: nil) }

  context 'first time' do
    it { expect{ subject }.not_to raise_error }
  end

  context 'second time' do
    before { hoge.update!(store_time: Time.zone.now) }

    it { expect{ subject }.to raise_error(ActiveRecord::RecordInvalid) }
    # ここでエラーが出ない…
  end
end

時間依存のバリデーションに対して、このようなテストを書いていた自分が安易ではあるのですが、1秒でも違えば、ActiveRecord::RecordInvalidが出るはずではあるので、beforeとitの実行時間に1秒も差異がないのだと理解しました。

その後、テストはリファクタして、通したのですが、結局どのくらいの時間差があるのか、気になったので実験してみることにしました。

実験

まず最初に時間単位の確認です。
保存しようとするデータとDBのデータは何秒まで記録しているのか見ていきましょう。

pry(main)> Hoge.first.created_at
=> Tue, 05 Jun 2018 23:44:57 JST +09:00
pry(main)> Hoge.first.created_at.nsec
=> 0

ということはDB上ではnsecでは保存していないという事になります。つまり1秒以上ズレがないと、異なる値とは見なされないということですね。

それではRspecでbeforeとitの中でどのくらい時間にズレがあるか確かめてみましょう。下記のようにRspecを書きます。

describe 'test time' do
  before { puts 'before: ' + Time.zone.now.iso8601(6) }
  it { puts 'it:     ' + Time.zone.now.iso8601(6) }
end

そして実行してみると下記のようになりました。

  test time
before: 2018-10-21T16:14:10.802145+09:00
it:     2018-10-21T16:14:10.803911+09:00

つまり、約0.001秒程度しか差がないということですね…これでは同じ秒と見なされてしまいますし、ごくごく稀に通ってしまう可能性もあるので、かなり悪いテストを書いていたことになりますね…

反省です…

結論

beforeとitの実行時の時間差は1秒にも満たないので、時間依存のテストを描く場合は、その点を留意して、テストを書く必要がある。

Rspecのbeforeとitではどのくらい時差があるのか？

環境

背景

実験

結論