#900 Add magic encoding comment to generated files - Ruby on Rails

Type	To find
responsible:me	tickets assigned to you
tagged:"@high"	tickets tagged @high
milestone:next	tickets in the upcoming milestone
state:invalid	tickets with the state invalid
created:"last week"	tickets created last week
sort:number, importance, updated	tickets sorted by #, importance or updated
Combine keywords for powerful searching.
Use advanced searching »

This project is archived and is in readonly mode.

#900 ✓resolved

Add magic encoding comment to generated files

Reported by Luca Guidi | August 25th, 2008 @ 11:30 AM | in 2.x

I'm using memcached store and UTC time zone.


comment = Comment.first
Rails.cache.write('comment', comment)
cached_comment = Rails.cache.read('comment')

comment.updated_at # => "2008-08-25 10:05:32" # UTC
cached_comment.updated_at # => "2008-08-25 10:05:32" # UTC



comment.update_attributes :text => 'Nice post!'
Rails.cache.write('comment', comment)
cached_comment = Rails.cache.read('comment')

comment.updated_at # => "2008-08-25 10:06:09" # UTC
cached_comment.updated_at # => 2008-08-25 12:06:09" # local time

I believe it's a bug, because it doesn't behaves the same with other caching systems (:file_store and :memory_store). I experienced this problem with Rails 2.1.0 and current edge.

Comments and changes to this ticket

Geoff Buesing August 25th, 2008 @ 02:45 PM
From your post on the Core list, it sounds like you're setting config.time_zone, is that correct? If so, you'll need the bugfix to TimeWithZone Marshaling in 2-1-stable, which isn't in the 2.1.0 gem release:

http://github.com/rails/rails/co...

Also, please note this behavior with Ruby's marshaling of Time instances -- you'll always get a Time.local instance, even if you're marshaling a Time.utc instance:
```
>> t = Time.utc(2000,1,1)
=> Sat Jan 01 00:00:00 UTC 2000
>> tmarshaled = Marshal.dump t
=> "\004\bu:\tTime\r \000\031\200\000\000\000\000"
>> t2 = Marshal.load tmarshaled
=> Fri Dec 31 18:00:00 -0600 1999
```
Could you check the class of cached_comment.updated_at through the steps in your example and see if you're consistently dealing with either a Time or a TimeWithZone instance?
You flagged this item as spam.
Luca Guidi August 25th, 2008 @ 03:19 PM
I know this is the behavior of Ruby's marshaling, but it doesn't seems a consistent solution. Because: * This affects only the Memcached store * The first time I write the object to the cache it correctly stores the updated_at value (UTC), but following accesses will return local time. * The database values and cached values timestamps are different.

The linked commit doesn't solve this problem, because it affects both 2.1.0 and edge.

The updatet_at class is always TimeWithZone.
You flagged this item as spam.
Luca Guidi August 25th, 2008 @ 03:54 PM
It seems like Marshal can't properly (un)serialize models with @changed_attributes, maybe because timestamps inside that hash, are instances of Time instead of TimeWithZone.

http://pastie.org/259472
Geoff Buesing August 25th, 2008 @ 04:28 PM
Just to narrow things down -- if you comment out config.time_zone in environment.rb, and add

config.active_record.default_timezone = :utc

does the problem still occur?
You flagged this item as spam.
Luca Guidi August 25th, 2008 @ 04:41 PM
Yes it still occurs.
Geoff Buesing August 25th, 2008 @ 05:52 PM
Aha ok. That rules out TimeWithZone as a player here.

If you just write a plain Time.utc instance to the cache, and then retrieve it, what does it come back as?

Luca Guidi August 25th, 2008 @ 07:11 PM


>> utc = Time.utc(2000, 1, 1)
=> Sat Jan 01 00:00:00 UTC 2000
>> Rails.cache.write('utc', utc)
=> true
>> Rails.cache.read('utc')
=> Sat Jan 01 01:00:00 +0100 2000

Geoff Buesing August 25th, 2008 @ 07:45 PM
Ok, so I'm thinking the problem is this:

In your example, when you read the object from the db and immediately store it in the cache, updated_at is still a string, because datetime attributes aren't cast to Time objects until read_attribute is called. So when the object is marshaled and then unmarshaled, the string value of updated_at unmarshals fine.

However, when you update the object, updated_at is set to a Time object (Time.now.utc) -- so when you marshal and unmarshal, you get a Time.local object instead of a Time.utc object. This Time.local object will send the wrong value to the database if AR default_timezone is :utc (which it will be set to if you set config.time_zone).

How to fix this? One way would be, when storing an AR object in the db, call #utc on all time column values before we call #to_s(:db) on them, if AR default_timezone is :utc.
Geoff Buesing August 25th, 2008 @ 08:18 PM
...but of course that solution might break other apps that rely on the existing behavior, so maybe that's not such a good solution.

Luca Guidi August 25th, 2008 @ 09:09 PM

Calling explicitly #updated_at should force the type casting. Is it right? But, even if I force the type casting, invoking #updated_at, before cache the object, it returns the right value (UTC).

I also tried to directly assign the value and store the model again, it works fine (case 2), but when I save the object and re-cache, it returns the local time (case 3).


>> comment = Comment.first
=> #<Comment id: 865423346, post_id: 1, text: "Nice post.", created_at: "2008-08-25 19:51:22", updated_at: "2008-08-25 19:51:22">
>> comment.updated_at # forcing type casting with #read_attribute
=> Mon, 25 Aug 2008 19:51:22 UTC +00:00
>> Rails.cache.write('comment', comment)
=> true
>> Rails.cache.read('comment')
=> #<Comment id: 865423346, post_id: 1, text: "Nice post.", created_at: "2008-08-25 19:51:22", updated_at: "2008-08-25 19:51:22"> # UTC time, right



>> comment.updated_at = Time.now.utc # forcing UTC time
=> Mon Aug 25 19:55:27 UTC 2008
>> Rails.cache.write('comment', comment)
=> true
>> Rails.cache.read('comment')
=> #<Comment id: 865423346, post_id: 1, text: "Nice post.", created_at: "2008-08-25 19:51:22", updated_at: "2008-08-25 19:55:27"> # UTC time, right



>> comment.save
=> true
>> Rails.cache.write('comment', comment)
=> true
>> Rails.cache.read('comment')
=> #<Comment id: 865423346, post_id: 1, text: "Nice post.", created_at: "2008-08-25 19:51:22", updated_at: "2008-08-25 21:59:26"> # local time, wrong

Anyway, I think it's a Ruby marshaling bug:


>> utc = Time.now.utc
=> Mon Aug 25 20:07:39 UTC 2008
>> marshaled = Marshal.dump utc
=> "\004\bu:\tTime\r4\037\e\200]\377q\036"
>> Marshal.load marshaled
=> Mon Aug 25 22:07:39 +0200 2008

Geoff Buesing August 26th, 2008 @ 02:11 PM

Agreed, this issue is definitely due to the Ruby's Time marshaling ignoring the zone.

I think my diagnosis above is correct -- in the example below, note how the updated_at attribute in the @attributes hash remains a string ("2008-08-26 12:50:54") even after I call the #updated_at method, but then becomes a Time object (Tue Aug 26 12:55:08 UTC 2008) after I #update_attributes:


# in environment.rb
# config.time_zone = 'UTC' # this is commented out
# config.active_record.default_timezone = :utc

>> p = Post.first
=> #<Post id: 1, title: "testing", posted_at: "2000-01-01 06:00:00", created_at: "2008-06-28 04:24:53", updated_at: "2008-08-26 12:50:54">
>> p.instance_variable_get('@attributes')
=> {"updated_at"=>"2008-08-26 12:50:54", "title"=>"testing", "id"=>"1", "posted_at"=>"2000-01-01 06:00:00", "created_at"=>"2008-06-28 04:24:53"}
>> p.updated_at
=> Tue Aug 26 12:50:54 UTC 2008
>> p.instance_variable_get('@attributes')
=> {"updated_at"=>"2008-08-26 12:50:54", "title"=>"testing", "id"=>"1", "posted_at"=>"2000-01-01 06:00:00", "created_at"=>"2008-06-28 04:24:53"}
>> p.update_attributes :title => 'test123'
=> true
>> p.instance_variable_get('@attributes')
=> {"updated_at"=>Tue Aug 26 12:55:08 UTC 2008, "title"=>"test123", "id"=>"1", "posted_at"=>"2000-01-01 06:00:00", "created_at"=>"2008-06-28 04:24:53"}

...and here's an example of the bug appearing when you marshal an AR instance:


>> p=Post.first
=> #<Post id: 1, title: "test", posted_at: "2000-01-01 06:00:00", created_at: "2008-06-28 04:24:53", updated_at: "2008-06-28 04:24:53">
>> p.update_attributes :title => 'foo'
=> true
>> p.updated_at
=> Tue Aug 26 12:46:56 UTC 2008
>> marshaled = Marshal.dump p
=> "\004\bo:\tPost\t:\f@errorso:\031ActiveRecord::Errors\a;\006{\000:\n@base@\000:\020@attributes{\n\"\017updated_atu:\tTime\rL\037\e\200\220X\211\273\"\ntitle\"\bfoo\"\aid\"\0061\"\016posted_at\"\0302000-01-01 06:00:00\"\017created_at\"\0302008-06-28 04:24:53:\026@attributes_cache{\006\"\017updated_at@\n:\030@changed_attributes{\000"
>> unmarshaled = Marshal.load marshaled
=> #<Post id: 1, title: "foo", posted_at: "2000-01-01 06:00:00", created_at: "2008-06-28 04:24:53", updated_at: "2008-08-26 07:46:56">
>> unmarshaled.updated_at
=> Tue Aug 26 07:46:56 -0500 2008

Geoff Buesing August 26th, 2008 @ 02:11 PM
- no changes were found...
You flagged this item as spam.
Luca Guidi August 26th, 2008 @ 03:43 PM
This bug was solved in Ruby 1.9: http://eigenclass.org/hiki.rb?Ch...
Michael Koziarski August 26th, 2008 @ 03:47 PM
Perhaps the 'right' fix is to make sure that TimeWithZone marshalls correctly, and encourage people to switch to timezone_aware_attributes?
Geoff Buesing August 26th, 2008 @ 05:28 PM
Glad to hear this is solved in 1.9.

If we used TimeWithZone objects to set created_at and updated_at timestamps (via a call to #in_time_zone), the only vulnerable points for the Time marshaling bug would be for attributes where you explicitly opt out of time_zone_aware_attributes. I guess an explicit warning in the docs would be the best we could do for this case.

An alternate approach would be, when setting created_at/updated_at, explicitly call #to_s(:db) on these values, so the attributes hash just contains strings (which will marshal without problem.)

Geoff Buesing August 27th, 2008 @ 07:48 AM

Thinking this through -- really, given that 1.9 fixes Time marshaling, we can consider the 1.8 behavior buggy, and fix it in ActiveSupport.

I came up with this fix:


class Time
  if RUBY_VERSION < '1.9'
    class << self
      alias_method :_original_load, :_load

      def _load(marshaled_time)
        time = _original_load(marshaled_time)
        if time.instance_variable_get('@marshal_with_utc_coercion')
          time.send(:remove_instance_variable, '@marshal_with_utc_coercion')
          time.utc
        else
          time
        end
      end
    end

    alias_method :_original_dump, :_dump

    def _dump(*args)
      instance_variable_set('@marshal_with_utc_coercion', true) if utc?
      _original_dump(*args)
    end
  end
end


utc = Time.now.utc
utc_marshaled = Marshal.dump utc
utc_unmarshaled = Marshal.load utc_marshaled
puts utc_unmarshaled  # => Wed Aug 27 06:24:11 UTC 2008

local = Time.now
local_marshaled = Marshal.dump local
local_unmarshaled = Marshal.load local_marshaled
puts local_unmarshaled  # => Wed Aug 27 01:24:11 -0500 2008

I'll pull this fix in, unless anyone can think of a good reason not to. This should fix the problem originally identified with this ticket, plus other use cases that would currently be broken (e.g., storing a utc timestamp in the cache.)

Luca Guidi August 27th, 2008 @ 10:12 AM

I suggest a bit different code, because the #instance_variable_get call generates a warning if the time isn't UTC: warning: instance variable @marshal_with_utc_coercion not initialized.


class Time
  if RUBY_VERSION < '1.9'
    class << self
      alias_method :_original_load, :_load
      def _load(marshaled_time)
        time = _original_load(marshaled_time)
        utc = time.send(:remove_instance_variable, '@marshal_with_utc_coercion')
        utc ? time.utc : time
      end
    end

    alias_method :_original_dump, :_dump
    def _dump(*args)
      instance_variable_set('@marshal_with_utc_coercion', utc?)
      _original_dump(*args)
    end
  end
end

Of course if you don't like, we can surround with #silence_warnings.

Luca Guidi August 27th, 2008 @ 10:29 AM
- no changes were found...
- 0001-Fix-Ruby-1.9-Time-UTC-marshaling-bug.patch 2.2 KB
You flagged this item as spam.
Luca Guidi August 27th, 2008 @ 10:35 AM
- Tag changed from “activesupport, bug” to “activesupport, bug, patch, tested”
I attached a patch.
Repository August 27th, 2008 @ 02:59 PM
- State changed from “new” to “resolved”
(from [ce65a05c5b027175c3c541055081f82c8bfc36bf]) Fix Ruby's Time marshaling bug in pre-1.9 versions of Ruby: utc instances are now correctly unmarshaled with a utc zone instead of the system local zone [#900 state:resolved] http://github.com/rails/rails/co...
Geoff Buesing August 27th, 2008 @ 03:02 PM
- State changed from “resolved” to “new”
- Tag changed from “activesupport, bug, patch, tested” to “activesupport, bug”
Good catch on the warning, and thanks for the patch. I added logic to cope with frozen objects.
Geoff Buesing August 27th, 2008 @ 03:03 PM
- State changed from “new” to “resolved”
Michael Koziarski August 27th, 2008 @ 03:05 PM
Geoff: Unless there's a reason not to, it seems like something we should merge into 2-1-stable too
Repository August 27th, 2008 @ 03:14 PM
(from [4d71e99d1fc1f57900288e008d7528c339138cf0]) Fix Ruby's Time marshaling bug in pre-1.9 versions of Ruby: utc instances are now correctly unmarshaled with a utc zone instead of the system local zone [#900 state:resolved] http://github.com/rails/rails/co...
Ryan Bigg October 9th, 2010 @ 10:13 PM
- Tag cleared.
- Importance changed from “” to “Low”
Automatic cleanup of spam.
Ryan Bigg October 21st, 2010 @ 03:39 AM
Automatic cleanup of spam.
You flagged this item as spam.
bingbing March 26th, 2011 @ 01:16 AM
luxury watch
You flagged this item as spam.
bingbing March 26th, 2011 @ 01:16 AM
luxury watch
You flagged this item as spam.
links london April 1st, 2011 @ 09:30 AM
links