Rails Time Comparisons: Devil, Details, etc.

Have you ever seen an error in your code where two timestamps that are the same fail a comparison test?

[sourcecode]
1) SomeController#update sets updated_at to current time
Failure/Error: something.reload.updated_at.should == Time.now
expected: 2011-08-04 15:09:26 +0000,
got: Thu, 04 Aug 2011 15:09:26 UTC +00:00 (using ==)
Diff:
@@ -1,2 +1,2 @@
-2011-08-04 15:09:26 +0000
+Thu, 04 Aug 2011 15:09:26 UTC +00:00
# ./spec/controllers/some_controller_spec.rb:41:in `block (3 levels) in [/sourcecode]

The times being compared are the same.  What gives?

One potential problem is that two consecutive calls to Time.now will differ in their fractional seconds.  The timecop gem makes it easier to write tests with time comparions by letting you freeze Time.now.

Even if you use timecop, you could still run into trouble:  Ruby Time values hold nanosecond precision, but most databases supported by ActiveRecord only support second or microsecond precision.  So if your frozen time came from Time.now, comparisons may not work as expected.

  1. Use updated_at.to_i and Time.now.to_i
  2. Stub Time.now (or use timecop) with a Time that’s rounded to seconds (e.g., Time.at(Time.now.to_i))

Read more to see the details.

Red Flag #1:  Time vs. ActiveSupport::TimeWithZone

The first telltale is that the times are printed in different formats: 2011-08-04 15:09:26 +0000 vs. Thu, 04 Aug 2011 15:09:26 UTC +00:00.

Let’s try some experiments in irb:

[sourcecode]
ruby-1.9.2-p180 :003 > Session.find(1).updated_at
=> Tue, 29 Mar 2011 22:23:36 UTC +00:00
ruby-1.9.2-p180 :004 > Session.find(1).updated_at.class
=> ActiveSupport::TimeWithZone
ruby-1.9.2-p180 :005 > Time.now
=> 2011-08-04 12:56:36 -0700
ruby-1.9.2-p180 :006 > Time.now.class
=> Time
[/sourcecode]

The record coming out of the database is an ActiveSupport::TimeWithZone, but Time.now is a Time.

The ActiveRecord documentation helps a little.  You can use Time.zone.now to get a value of the same type as the updated_at field:

[sourcecode]
ruby-1.9.2-p180 :011 > Time.zone.now
=> Thu, 04 Aug 2011 20:00:21 UTC +00:00
ruby-1.9.2-p180 :012 > Time.zone.now.class
=> ActiveSupport::TimeWithZone
ruby-1.9.2-p180 :013 >
[/sourcecode]

Red Flag #2: ActiveSupport::TimeWithZone isn’t comparable with itself

Unfortunately, using Time.zone.now doesn’t help.  Re-reading from the database makes the time values incomparable:

[sourcecode]
ruby-1.9.2-p180 :029 > record
=> #
ruby-1.9.2-p180 :030 > x = Time.zone.now
=> Fri, 05 Aug 2011 23:06:23 UTC +00:00
ruby-1.9.2-p180 :031 > record.created_at = x
=> Fri, 05 Aug 2011 23:06:23 UTC +00:00
ruby-1.9.2-p180 :032 > record.created_at == x
=> true
ruby-1.9.2-p180 :033 > record.save
=> true
ruby-1.9.2-p180 :034 > record.created_at == x
=> true
ruby-1.9.2-p180 :035 > record.reload
=> #
ruby-1.9.2-p180 :036 > record.created_at == x
=> false
ruby-1.9.2-p180 :037 >
[/sourcecode]

Before calling reload, the comparison behaves as expected (look for “:034”).  After the reload, the comparison fails.

Underlying Issue: Ruby Time is more precise than DB time

What’s special about reloading the model?  It looks like the Ruby Time object maintains greater precision than the database does.  When the value is read back from the database, it’s only preserved to microsecond precision, while the in-memory representation is precise to nanoseconds.
[sourcecode]ruby-1.9.2-p180 :021 > record.created_at.nsec
=> 609020000
ruby-1.9.2-p180 :022 > x.nsec
=> 609020403
ruby-1.9.2-p180 :023 >[/sourcecode]

Workarounds and Potential Fixes

You can avoid this issue by comparing times in seconds, assuming you don’t care about msec/usec precision:
[sourcecode]record.updated_at.to_i == x.to_i[/sourcecode]
Another approach (especially valuable in tests) is to not use an arbitrary Time.now (or e.g. 5.days.ago), but instead to stub Time.now with a round Time value  — e.g. no nanoseconds.
[sourcecode]
ruby-1.9.2-p180 :026 > y = Time.at(1312700983)
=> 2011-08-07 00:09:43 -0700
ruby-1.9.2-p180 :027 > y.nsec
=> 0
ruby-1.9.2-p180 :028 > record.updated_at = y
=> 2011-08-07 00:09:43 -0700
ruby-1.9.2-p180 :029 > record.save
=> true
ruby-1.9.2-p180 :030 > record.reload
=> #<Record id: 1, email: "foo@bar.com", created_at: "2011-08-05 23:06:23", updated_at: "2011-08-07 07:09:43">
ruby-1.9.2-p180 :031 > i.updated_at == y
=> true
[/sourcecode]
A patch to timecop to round all input times to seconds would help.

A long-term solution is a little more complex.

Different database backends supported by ActiveRecord offer different time precisions:

It would be slick to detect the database backend and use it to determine the precision of time comparisons, but that’s probably overkill.

6 Comments

  • doesterr August 19, 2011 at 7:20 pm

    I like to use record.updated_at.utc.to_s instead of record.updated_at.to_i

    with this I get a more meaningful output from my assertions

  • Rob Morris February 8, 2013 at 4:26 am

    Another gotcha – TimeWithZone’s == operator returns true if two times specify the same UTC time, but in different timezones. That one got me today, not an expected result!

  • ronenbarzel April 2, 2013 at 3:17 pm

    Thanks for providing clarity. Reading this post suggested to me another workaround for the time precision difference: rather than changing equality tests in the specs, patch TimeWithZone to test equality at whole-second granularity.

    In specs/support/time_with_zone.rb:

    # Use 1-second granularity when comparing times.
    # See http://blog.tddium.com/2011/08/07/rails-time-comparisons-devil-details-etc/
    class ActiveSupport::TimeWithZone
    def ==(other)
    self.to_i == other.to_i
    end
    end

    A fancier version of this could detect the database and use the appropriate precision, as you suggested.

  • Luke Redpath April 24, 2014 at 3:29 pm

    This is an old, but useful post. Another gotcha worth pointing out – I had some test comparisons that were passing locally but not on our CI server. As in the above example, we were comparing an ActiveRecord timestamp (from Postgres), with microsecond precision, to Time.zone.now. The reason it passed locally for me is because OSX only supports microsecond precision so my time comparisons always worked. On our CI server (Linux), it supports nanosecond precision hence I was having the issue outlined in this article. Hope that’s useful to somebody in the future!

    • Andrei Horak December 8, 2015 at 1:20 am

      Indeed, this is very useful! Thanks for pointing this out!

    • Todd Morningstar July 25, 2016 at 8:45 am

      Also concur, thanks for the thorough details on this issue. Ive resolved a lot of time related spec assertions/expectations by just conforming everything to the ActiveSupport class, but was still missing due to the nanosecond vs microsecond issue.

Post a Comment