rspec users - Nov 2009 - "lambda Should Change" Behavior Failing When Checking Time

Hello,

I''m having a problem with RSpec when using the "lambda should
change behavior".

This is happening in a Rails 2.3.4 app and I''m running the following
in my test environment:

''cucumber'', :version => ''0.4.2''
''faker'', :version => ''0.3.1''
''notahat-machinist'', :lib => ''machinist'',
:version => ''1.0.3''
"remarkable_rails", :lib => false
''rspec'', :lib => false, :version =>
''1.2.9''
''rspec-rails'', :lib => false, :version =>
''1.2.9''
''jtrupiano-timecop'', :lib => ''timecop'',
:version => ''0.3.0''
''webrat'', :lib => false, :version =>
''0.5.1''
''fakeweb'', :lib => false, :version =>
''1.2.6''

In my application, I have a Post model that is using Rubyist''s AASM
gem. The aasm column is defined as ''state''. The other column
of note
is ''published_at''; this is defined as a datetime.

These are the settings for the state machine:

  aasm_column :state
  aasm_initial_state :draft
  aasm_state :draft
  aasm_state :published, :enter => :set_published
  aasm_event :publish do
    transitions :to => :published, :from => :draft
  end

set_published is a method that is defined as:

  def set_published
    self.update_attributes(:published_at => Time.now)
  end

For those that are unfamiliar with Rubyist''s AASM, defining an
aasm_event gives you an bang instance method with the same name of the
aasm_event. For example, I have :publish defined as an aasm_event and
because of this I can call the publish! method on an instance of a
Post. This will change the state from ''draft'' to
''published''. It will
also call the set_published method as defined by the :enter statement.

This is my first spec attempt. I''ve removed all of the post attributes
for brevity.

describe "AASM States" do
  before(:each) do
    @post = Post.create([snip...post attributes here])
  end

  it "should set the publish date to now when transitioning to
published" do
    lambda { @post.publish! }.should change(@post,
:published_at).from(nil).to(Time.now)
  end
end

This fails with a message like the following:

published_at should have been changed to Sat Nov 07 15:02:00 -0800
2009, but is now Sat Nov 07 15:02:00 -0800 2009

*blink* *blink*

They appear to be the same.

Just in case the time was being altered by milliseconds that I
couldn''t see, I tried using jtrupiano''s Timecop gem to freeze
time and
check against the frozen time.

    it "should set the publish date to now when transitioning to
published" do
      time = Time.now
      Timecop.freeze(time)
      lambda { @post.publish! }.should change(@post,
:published_at).from(nil).to(time)
      Timecop.return
    end

This still gives me the same failure message. For those unfamiliar
with Timecop, here is how it works (in the console):
>> require ''Timecop''
=> []
>> time = Timecop.freeze(Time.now)
=> Sat Nov 07 15:07:32 -0800 2009
>> sleep(10)
=> 10
>> time == Time.now
=> true
>> Timecop.return
=> Sat Nov 07 15:08:09 -0800 2009
>> time == Time.now
=> false

In development, I know that the published_at time is truly
transitioning from nil to an actual time, I just don''t know why
it''s
failing in the spec and even stranger when RSpec tells me that they
are the (supposedly) the same.
>From the development console:
>> p = Post.new([snip...post attributes here])
>> p.save
=> true
>> p.published_at
=> nil
>> p.publish!
=> true
>> p.published_at
=> Sat Nov 07 15:10:22 -0800 2009

Is there something that I''m missing?

Thank you in advance for your help,

Carlos

On Sat, Nov 7, 2009 at 6:18 PM, Carlos Rodriguez <carlos at eddorre.com>
wrote:
> Hello,
>
> I''m having a problem with RSpec when using the "lambda should
change
> behavior".
>
> This is happening in a Rails 2.3.4 app and I''m running the
following
> in my test environment:
>
> ''cucumber'', :version => ''0.4.2''
> ''faker'', :version => ''0.3.1''
> ''notahat-machinist'', :lib =>
''machinist'', :version => ''1.0.3''
> "remarkable_rails", :lib => false
> ''rspec'', :lib => false, :version =>
''1.2.9''
> ''rspec-rails'', :lib => false, :version =>
''1.2.9''
> ''jtrupiano-timecop'', :lib =>
''timecop'', :version => ''0.3.0''
> ''webrat'', :lib => false, :version =>
''0.5.1''
> ''fakeweb'', :lib => false, :version =>
''1.2.6''
>
> In my application, I have a Post model that is using Rubyist''s
AASM
> gem. The aasm column is defined as ''state''. The other
column of note
> is ''published_at''; this is defined as a datetime.
>
> These are the settings for the state machine:
>
>  aasm_column :state
>  aasm_initial_state :draft
>  aasm_state :draft
>  aasm_state :published, :enter => :set_published
>  aasm_event :publish do
>    transitions :to => :published, :from => :draft
>  end
>
> set_published is a method that is defined as:
>
>  def set_published
>    self.update_attributes(:published_at => Time.now)
>  end
>
> For those that are unfamiliar with Rubyist''s AASM, defining an
> aasm_event gives you an bang instance method with the same name of the
> aasm_event. For example, I have :publish defined as an aasm_event and
> because of this I can call the publish! method on an instance of a
> Post. This will change the state from ''draft'' to
''published''. It will
> also call the set_published method as defined by the :enter statement.
>
> This is my first spec attempt. I''ve removed all of the post
attributes
> for brevity.
>
> describe "AASM States" do
>  before(:each) do
>    @post = Post.create([snip...post attributes here])
>  end
>
>  it "should set the publish date to now when transitioning to
published" do
>    lambda { @post.publish! }.should change(@post,
> :published_at).from(nil).to(Time.now)
>  end
> end
>
> This fails with a message like the following:
>
> published_at should have been changed to Sat Nov 07 15:02:00 -0800
> 2009, but is now Sat Nov 07 15:02:00 -0800 2009
>
> *blink* *blink*
>
> They appear to be the same.
>
> Just in case the time was being altered by milliseconds that I
> couldn''t see, I tried using jtrupiano''s Timecop gem to
freeze time and
> check against the frozen time.
>
>    it "should set the publish date to now when transitioning to
published"
> do
>      time = Time.now
>      Timecop.freeze(time)
>      lambda { @post.publish! }.should change(@post,
> :published_at).from(nil).to(time)
>      Timecop.return
>    end
>
> This still gives me the same failure message. For those unfamiliar
> with Timecop, here is how it works (in the console):
>
> >> require ''Timecop''
> => []
> >> time = Timecop.freeze(Time.now)
> => Sat Nov 07 15:07:32 -0800 2009
> >> sleep(10)
> => 10
> >> time == Time.now
> => true
> >> Timecop.return
> => Sat Nov 07 15:08:09 -0800 2009
> >> time == Time.now
> => false
>
> In development, I know that the published_at time is truly
> transitioning from nil to an actual time, I just don''t know why
it''s
> failing in the spec and even stranger when RSpec tells me that they
> are the (supposedly) the same.
>
> >From the development console:
>
> >> p = Post.new([snip...post attributes here])
> >> p.save
> => true
> >> p.published_at
> => nil
> >> p.publish!
> => true
> >> p.published_at
> => Sat Nov 07 15:10:22 -0800 2009
>
> Is there something that I''m missing?
>
> Thank you in advance for your help,
>
Hi Carlos,

I would definitely assume that the times are off by milliseconds here and
that the to_s method simply produces the same result on two different times.

Not sure why it''s still failing even when using Timecop, though.
Perhaps
somebody else has some ideas about that.

HTH,
David

>
> Carlos
> _______________________________________________
> rspec-users mailing list
> rspec-users at rubyforge.org
> http://rubyforge.org/mailman/listinfo/rspec-users
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://rubyforge.org/pipermail/rspec-users/attachments/20091107/8abe76b6/attachment.html>

David Chelimsky escreveu:
> On Sat, Nov 7, 2009 at 6:18 PM, Carlos Rodriguez <carlos at eddorre.com 
> <mailto:carlos at eddorre.com>> wrote:
>
>     Hello,
>
>     I''m having a problem with RSpec when using the "lambda
should
>     change behavior".
>
>     This is happening in a Rails 2.3.4 app and I''m running the
following
>     in my test environment:
>
>     ''cucumber'', :version => ''0.4.2''
>     ''faker'', :version => ''0.3.1''
>     ''notahat-machinist'', :lib =>
''machinist'', :version => ''1.0.3''
>     "remarkable_rails", :lib => false
>     ''rspec'', :lib => false, :version =>
''1.2.9''
>     ''rspec-rails'', :lib => false, :version =>
''1.2.9''
>     ''jtrupiano-timecop'', :lib =>
''timecop'', :version => ''0.3.0''
>     ''webrat'', :lib => false, :version =>
''0.5.1''
>     ''fakeweb'', :lib => false, :version =>
''1.2.6''
>
>     In my application, I have a Post model that is using Rubyist''s
AASM
>     gem. The aasm column is defined as ''state''. The other
column of note
>     is ''published_at''; this is defined as a datetime.
>
>     These are the settings for the state machine:
>
>      aasm_column :state
>      aasm_initial_state :draft
>      aasm_state :draft
>      aasm_state :published, :enter => :set_published
>      aasm_event :publish do
>        transitions :to => :published, :from => :draft
>      end
>
>     set_published is a method that is defined as:
>
>      def set_published
>        self.update_attributes(:published_at => Time.now)
>      end
>
>     For those that are unfamiliar with Rubyist''s AASM, defining an
>     aasm_event gives you an bang instance method with the same name of the
>     aasm_event. For example, I have :publish defined as an aasm_event and
>     because of this I can call the publish! method on an instance of a
>     Post. This will change the state from ''draft'' to
''published''. It will
>     also call the set_published method as defined by the :enter statement.
>
>     This is my first spec attempt. I''ve removed all of the post
attributes
>     for brevity.
>
>     describe "AASM States" do
>      before(:each) do
>        @post = Post.create([snip...post attributes here])
>      end
>
>      it "should set the publish date to now when transitioning to
>     published" do
>        lambda { @post.publish! }.should change(@post,
>     :published_at).from(nil).to(Time.now)
>      end
>     end
>
>     This fails with a message like the following:
>
>     published_at should have been changed to Sat Nov 07 15:02:00 -0800
>     2009, but is now Sat Nov 07 15:02:00 -0800 2009
>
>     *blink* *blink*
>
>     They appear to be the same.
>
>     Just in case the time was being altered by milliseconds that I
>     couldn''t see, I tried using jtrupiano''s Timecop gem
to freeze time and
>     check against the frozen time.
>
>        it "should set the publish date to now when transitioning to
>     published" do
>          time = Time.now
>          Timecop.freeze(time)
>          lambda { @post.publish! }.should change(@post,
>     :published_at).from(nil).to(time)
>          Timecop.return
>        end
>
>     This still gives me the same failure message. For those unfamiliar
>     with Timecop, here is how it works (in the console):
>
>     >> require ''Timecop''
>     => []
>     >> time = Timecop.freeze(Time.now)
>     => Sat Nov 07 15:07:32 -0800 2009
>     >> sleep(10)
>     => 10
>     >> time == Time.now
>     => true
>     >> Timecop.return
>     => Sat Nov 07 15:08:09 -0800 2009
>     >> time == Time.now
>     => false
>
>     In development, I know that the published_at time is truly
>     transitioning from nil to an actual time, I just don''t know
why it''s
>     failing in the spec and even stranger when RSpec tells me that they
>     are the (supposedly) the same.
>
>     >From the development console:
>
>     >> p = Post.new([snip...post attributes here])
>     >> p.save
>     => true
>     >> p.published_at
>     => nil
>     >> p.publish!
>     => true
>     >> p.published_at
>     => Sat Nov 07 15:10:22 -0800 2009
>
>     Is there something that I''m missing?
>
>     Thank you in advance for your help,
>
>
> Hi Carlos,
>
> I would definitely assume that the times are off by milliseconds here 
> and that the to_s method simply produces the same result on two 
> different times.
>
> Not sure why it''s still failing even when using Timecop, though. 
> Perhaps somebody else has some ideas about that.
I believe Timecop doesn''t help in this case.

ActiveRecord will probably fill the time using SQL now() instead of 
Time.now.

Anyway, I wouldn''t bother to test if the time was changed to now. I 
think it suffices to test that time was changed from nil.

If you really want to test that it changed to now, I would write 
something like:

@post.published_at.should be_nil
@post.publish!
(Time.now - @post.published_at).should have_at_most(1).second

Or you could write a new matcher if you need to check this often... But 
I think this is an already tested ActiveRecord behavior and that you 
should test only your code and rely on ActiveRecord to fill the 
corrected timestamp.

Good luck,

Rodrigo.
__________________________________________________
Fa?a liga??es para outros computadores com o novo Yahoo! Messenger 
http://br.beta.messenger.yahoo.com/

On Nov 08, 2009, at 10:39 am, Rodrigo Rosenfeld Rosas wrote:
> @post.published_at.should be_nil
> @post.publish!
> (Time.now - @post.published_at).should have_at_most(1).second
FWIW, this is what I do too, although I normally use "should <" or
"be_close", but the idea is the same.  You only need to worry about  
more accuracy than that if it''s time-critical.

Also, I''ve found meddling with Time breaks RSpec''s timing -
don''t know
if that''s still the case.  For times when I really care about timing,  
I''ve made a Clock class, and have everything use that, instead of Time
directly.

Ashley

-- 
http://www.patchspace.co.uk/
http://www.linkedin.com/in/ashleymoran

Thanks to everyone that responded to my question.

Here is what I ended up doing to make the spec pass:

time_now = Time.now
Time.stub!(:now).and_return(time_now)
lambda { @post.publish! }.should change(@post,
:published_at).from(nil).to(time_now)

Carlos

Carlos Rodriguez escreveu:
> Thanks to everyone that responded to my question.
>
> Here is what I ended up doing to make the spec pass:
>
> time_now = Time.now
> Time.stub!(:now).and_return(time_now)
> lambda { @post.publish! }.should change(@post,
> :published_at).from(nil).to(time_now)
>   
I have thought on this approach after I realized that ActiveRecord would 
not probably populate this field using SQL since it doesn''t know per 
itself about published_at attribute and I realized that you probably 
used something like "published_at = Time.now" on an after_save or 
before_save hook.

I would suggest you this approach but then, in the middle of the message 
I realized it wouldn''t be a good idea to mock the Time class, since it 
wouldn''t test what you want, I thought...

Unless you really care if the implementation uses Time.now to fill the 
published_at field (instead of a SQL now(), or some trigger...), the 
other alternative would be less dependent on implementation...

And looking at the complete solution, I really don''t think it is
clearer
or more compact to read :)

But I guess you were intrigued on how to do that :) It happens to me 
sometimes... Today, I''ve spent the morning reading Rspec and Webrat 
internals just to figure out that the error I was getting was really a 
silly mistake (I was using assert_not_contain before requesting a URL).

Sometimes, things just bother us because we actually want to know how 
something works... I was really intrigued about what describe/context/it 
did from behind the scenes. And even more intrigued in trying to 
understand how webrat integration works. Every time I had a problem, I 
blessed the fact that I didn''t understand the internals, but, although 
knowing the internals better helps to solve all sort of confusion, the 
problem usually is something simpler :)

But, at least, it is good when we solve all the mystery, right? :)

Good night,

Rodrigo.

__________________________________________________
Fa?a liga??es para outros computadores com o novo Yahoo! Messenger 
http://br.beta.messenger.yahoo.com/