Lighthouse has a new layout. Prefer the old one? Return to the old layout, and switch back any time from the link at the top of each page.

This project is archived and is in readonly mode.

Rails loses precision when deserializing timestamps from Postgresql

#4498

When a timestamp is serialized/deserialized out of/into PostgreSQL, sometimes they do not match. The following code will reproduce the issue after no more than ~100 iterations.

Repro:
1. Get a rails project connected to a Postgres DB
2. Create a table in Postgres called 'tmps'. From psql console:

CREATE TABLE tmps (id bigserial, atime timestamp with time zone );

  1. Open the Rails console, run the following code:

class Tmp < ActiveRecord::Base

end
t = Tmp.create(:atime => Time.now)
conn = Tmp.connection
10000.times do
conn.select_one "UPDATE tmps SET atime = NOW()" ret_time = Tmp.find(t.id).atime result = conn.select_one("SELECT atime = #{conn.quote(ret_time)} AS tst, atime FROM tmps WHERE id = #{t.id}")

formatted = ret_time.strftime("%a %b %d %H:%M:%S.#{ret_time.usec} %Z %Y") if(result['tst'] != 't')

raise "oops! Rails value '#{formatted}' not the same as SQL value '#{result['atime']}'"

else

STDERR.puts("Rails time '#{formatted}' matches SQL time '#{result['atime']}'")

end end

After some iterations, the exception will raise. This was observed against Rails 2.3.5.

Reported by Logan Bowers · April 29th, 2010 @ 02:19 AM

State: stale
Milestone: none
Assigned to: nobody
Importance: none

Activity

  1. Logan Bowers
    Logan Bowers

    Let me try adding that Ruby code again:

    class Tmp < ActiveRecord::Base
    
    end
    t = Tmp.create(:atime => Time.now)
    conn = Tmp.connection
    10000.times do 
      conn.select_one "UPDATE tmps SET atime = NOW()"
      ret_time = Tmp.find(t.id).atime
      result = conn.select_one("SELECT atime = #{conn.quote(ret_time)} AS tst, atime FROM tmps WHERE id = #{t.id}")
      
      formatted = ret_time.strftime("%a %b %d %H:%M:%S.#{ret_time.usec} %Z %Y")
      if(result['tst'] != 't')
        raise "oops! Rails value '#{formatted}' not the same as SQL value '#{result['atime']}'"
      else
        STDERR.puts("Rails time '#{formatted}' matches SQL time '#{result['atime']}'")
      end
    end
    

    April 29th, 2010 @ 02:22 AM

  2. Logan Bowers
    Logan Bowers

    Adding a patch that fixes the issue in 2-3-stable. ActiveRecord::ConnectionAdapters::Column#microseconds did an unnecessary conversion to from Rational to float when calculating the integer number of microseconds. Some terminating decimal numbers in base10 are repeating decimal numbers in base2 (the format of float), and occasionally this causes a rounding error.

    I will add a patch for Rails 3 if the problem still exists.

    April 29th, 2010 @ 07:32 PM

  3. Logan Bowers
    Logan Bowers

    The problem does exist in master (as of f4d174b211effd4cd510c1578bdc391852f4d375), this patch should also apply with minimal fuzzing.

    April 29th, 2010 @ 07:35 PM

  4. Logan Bowers
    Logan Bowers
    • Tag changed from 2.3.5, activerecord, postgresql, timestamp to 2.3.5, activerecord, patch, postgresql, timestamp

    April 29th, 2010 @ 07:35 PM

  5. Logan Bowers
    Logan Bowers
    diff --git a/activerecord/lib/active_record/connection_adapters/abstract/schema_definitions.rb b/activerecord/lib/active_record/connection_adapters/abstract/schema_definitions.rb
    index 520f3c8..2a2e38a 100644
    --- a/activerecord/lib/active_record/connection_adapters/abstract/schema_definitions.rb
    +++ b/activerecord/lib/active_record/connection_adapters/abstract/schema_definitions.rb
    @@ -170,7 +170,7 @@ module ActiveRecord
               # '0.123456' -> 123456
               # '1.123456' -> 123456
               def microseconds(time)
    -            ((time[:sec_fraction].to_f % 1) * 1_000_000).to_i
    +            time[:sec_fraction] ? (time[:sec_fraction] * 1_000_000).to_i : 0
               end
     
               def new_date(year, mon, mday)
    -- 
    1.6.6.1
    

    Here's an updated patch. time[:sec_fraction] is nil when there are no microseconds and nil.to_f is 0.0. Thus, there needs to be a nil-check before attempting the multiplication.

    May 6th, 2010 @ 10:56 PM

  6. Dan Pickett
    Dan Pickett
    • Tag changed from 2.3.5, activerecord, patch, postgresql, timestamp to 2.3.5, activerecord, bugmash, patch, postgresql, timestamp

    May 9th, 2010 @ 07:25 PM

  7. Joe Van Dyk
    Joe Van Dyk

    I'm sort of confused by your test case.

    After updating all the records to now(), why would you expect them to match an earlier time?

    If you're not inside a transaction, now() will change each time you call it.

    November 23rd, 2010 @ 09:36 PM

  8. Logan Bowers
    Logan Bowers

    Each time through the loop a single row is updated to an arbitrary time. Then that row is retrieved and the time is converted to a Ruby object. The Ruby object is converted back to a string and compared to the original value in the SQL row. Occasionally Ruby will encounter a rounding error and be off by one microsecond. When this happens, the SQL dates are no longer equal and the SQL SELECT statement returns 'f' (false).

    December 2nd, 2010 @ 09:55 PM

  9. Logan Bowers
    Logan Bowers

    The loop is just because it will happen eventually. I could have run this code to find an exact fail case and substituted the NOW() call with the exact timestamp that fails.

    December 2nd, 2010 @ 09:57 PM

  10. rails
    rails
    • Tag changed from 2.3.5, activerecord, bugmash, patch, postgresql, timestamp to 235, activerecord, bugmash, patch, postgresql, timestamp
    • State changed from new to open

    This issue has been automatically marked as stale because it has not been commented on for at least three months.

    The resources of the Rails core team are limited, and so we are asking for your help. If you can still reproduce this error on the 3-0-stable branch or on master, please reply with all of the information you have about it and add "[state:open]" to your comment. This will reopen the ticket for review. Likewise, if you feel that this is a very important feature for Rails to include, please reply with your explanation so we can consider it.

    Thank you for all your contributions, and we hope you will understand this step to focus our efforts where they are most helpful.

    March 5th, 2011 @ 12:00 AM

  11. rails
    rails
    • State changed from open to stale

    March 5th, 2011 @ 12:00 AM