rack-devel archive mirror (unofficial) https://groups.google.com/group/rack-devel
 help / color / mirror / code / Atom feed
* Rack test spec_rack_runtime fails on JRuby due to timing
@ 2010-01-17 18:20 Charles Oliver Nutter
  2010-01-18  6:38 ` Ryan Tomayko
  0 siblings, 1 reply; 5+ messages in thread
From: Charles Oliver Nutter @ 2010-01-17 18:20 UTC (permalink / raw)
  To: Rack Development

Hey, the following test currently fails on JRuby, but not for a very
good reason:

  specify "should allow multiple timers to be set" do
    app = lambda { |env| sleep 0.1; [200, {'Content-Type' => 'text/
plain'}, "Hello, World!"] }
    runtime1 = Rack::Runtime.new(app, "App")
    runtime2 = Rack::Runtime.new(runtime1, "All")
    response = runtime2.call({})

    response[1]['X-Runtime-App'].should =~ /[\d\.]+/
    response[1]['X-Runtime-All'].should =~ /[\d\.]+/

    Float(response[1]['X-Runtime-All']).should > Float(response[1]['X-
Runtime-App'])
  end

The test here is trying to time that the "All" timer is longer than
the "App" timer. Unfortunately, when running on JRuby, the All time is
often below 1ms, which is shorter than the granularity for our Time
class (JVM only provides current time to 1ms granularity). As a
result, the test usually fails.

This came up because a friend of JRuby is working to prepare a Gentoo
ebuild, and wants to get all related packages running green.

I'm not sure the best way to fix this; the difference in execution
time between the "App" and the "All" wrapper are very small, and a
timing test like this is probably going to be unpredictable. I have
made a JRuby-specific patch here to use the JVM's nanosecond timer
(which can be used for deltas but not absolute times), but it's
obviously JRuby-specific:

http://gist.github.com/279475

Running the tests with this modification shows the "All" time to range
around 0.00015s and the "App" time around 0.00003s.

Thoughts?

- Charlie

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: Rack test spec_rack_runtime fails on JRuby due to timing
  2010-01-17 18:20 Rack test spec_rack_runtime fails on JRuby due to timing Charles Oliver Nutter
@ 2010-01-18  6:38 ` Ryan Tomayko
  2010-01-18  6:59   ` Christian Neukirchen
  0 siblings, 1 reply; 5+ messages in thread
From: Ryan Tomayko @ 2010-01-18  6:38 UTC (permalink / raw)
  To: rack-devel

On Sun, Jan 17, 2010 at 10:20 AM, Charles Oliver Nutter
<headius@headius.com> wrote:
> Hey, the following test currently fails on JRuby, but not for a very
> good reason:
>
>  specify "should allow multiple timers to be set" do
>    app = lambda { |env| sleep 0.1; [200, {'Content-Type' => 'text/
> plain'}, "Hello, World!"] }
>    runtime1 = Rack::Runtime.new(app, "App")
>    runtime2 = Rack::Runtime.new(runtime1, "All")
>    response = runtime2.call({})
>
>    response[1]['X-Runtime-App'].should =~ /[\d\.]+/
>    response[1]['X-Runtime-All'].should =~ /[\d\.]+/
>
>    Float(response[1]['X-Runtime-All']).should > Float(response[1]['X-
> Runtime-App'])
>  end
>
> The test here is trying to time that the "All" timer is longer than
> the "App" timer. Unfortunately, when running on JRuby, the All time is
> often below 1ms, which is shorter than the granularity for our Time
> class (JVM only provides current time to 1ms granularity). As a
> result, the test usually fails.
>
> This came up because a friend of JRuby is working to prepare a Gentoo
> ebuild, and wants to get all related packages running green.
>
> I'm not sure the best way to fix this; the difference in execution
> time between the "App" and the "All" wrapper are very small, and a
> timing test like this is probably going to be unpredictable. I have
> made a JRuby-specific patch here to use the JVM's nanosecond timer
> (which can be used for deltas but not absolute times), but it's
> obviously JRuby-specific:
>
> http://gist.github.com/279475
>
> Running the tests with this modification shows the "All" time to range
> around 0.00015s and the "App" time around 0.00003s.
>
> Thoughts?

Perhaps changing the assertion to be:

    Float(response[1]['X-Runtime-All']).should >=
Float(response[1]['X-Runtime-App'])

... or removing the assertion entirely.

Thanks,
Ryan

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: Rack test spec_rack_runtime fails on JRuby due to timing
  2010-01-18  6:38 ` Ryan Tomayko
@ 2010-01-18  6:59   ` Christian Neukirchen
  2010-01-18 17:17     ` Charles Oliver Nutter
  0 siblings, 1 reply; 5+ messages in thread
From: Christian Neukirchen @ 2010-01-18  6:59 UTC (permalink / raw)
  To: rack-devel

On Mon, Jan 18, 2010 at 7:38 AM, Ryan Tomayko <r@tomayko.com> wrote:
> On Sun, Jan 17, 2010 at 10:20 AM, Charles Oliver Nutter
> <headius@headius.com> wrote:
>> Hey, the following test currently fails on JRuby, but not for a very
>> good reason:
>>
>>  specify "should allow multiple timers to be set" do
>>    app = lambda { |env| sleep 0.1; [200, {'Content-Type' => 'text/
>> plain'}, "Hello, World!"] }
>>    runtime1 = Rack::Runtime.new(app, "App")
>>    runtime2 = Rack::Runtime.new(runtime1, "All")
>>    response = runtime2.call({})
>>
>>    response[1]['X-Runtime-App'].should =~ /[\d\.]+/
>>    response[1]['X-Runtime-All'].should =~ /[\d\.]+/
>>
>>    Float(response[1]['X-Runtime-All']).should > Float(response[1]['X-
>> Runtime-App'])
>>  end
>>
>> The test here is trying to time that the "All" timer is longer than
>> the "App" timer. Unfortunately, when running on JRuby, the All time is
>> often below 1ms, which is shorter than the granularity for our Time
>> class (JVM only provides current time to 1ms granularity). As a
>> result, the test usually fails.
>>
>> This came up because a friend of JRuby is working to prepare a Gentoo
>> ebuild, and wants to get all related packages running green.
>>
>> I'm not sure the best way to fix this; the difference in execution
>> time between the "App" and the "All" wrapper are very small, and a
>> timing test like this is probably going to be unpredictable. I have
>> made a JRuby-specific patch here to use the JVM's nanosecond timer
>> (which can be used for deltas but not absolute times), but it's
>> obviously JRuby-specific:
>>
>> http://gist.github.com/279475
>>
>> Running the tests with this modification shows the "All" time to range
>> around 0.00015s and the "App" time around 0.00003s.
>>
>> Thoughts?
>
> Perhaps changing the assertion to be:
>
>    Float(response[1]['X-Runtime-All']).should >=
> Float(response[1]['X-Runtime-App'])
>
> ... or removing the assertion entirely.

... or introducing/moving a second sleep.

> Thanks,
> Ryan
>
-- 
Christian Neukirchen  <chneukirchen@gmail.com>  http://chneukirchen.org

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: Rack test spec_rack_runtime fails on JRuby due to timing
  2010-01-18  6:59   ` Christian Neukirchen
@ 2010-01-18 17:17     ` Charles Oliver Nutter
  2010-02-08 19:38       ` Ryan Tomayko
  0 siblings, 1 reply; 5+ messages in thread
From: Charles Oliver Nutter @ 2010-01-18 17:17 UTC (permalink / raw)
  To: rack-devel

On Mon, Jan 18, 2010 at 12:59 AM, Christian Neukirchen
<chneukirchen@gmail.com> wrote:
> On Mon, Jan 18, 2010 at 7:38 AM, Ryan Tomayko <r@tomayko.com> wrote:
>> Perhaps changing the assertion to be:
>>
>>    Float(response[1]['X-Runtime-All']).should >=
>> Float(response[1]['X-Runtime-App'])
>>
>> ... or removing the assertion entirely.
>
> ... or introducing/moving a second sleep.

I made the following change on my (temporary) rack fork, which helps
ensure the times are long enough to be measurable:

http://github.com/headius/rack/commit/fb0a7378852b678315b403eb2061da73b4478a37

It's a little hacky, but it works well enough. Timing tests are
obviously hard to get right in any case.

- Charlie

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: Rack test spec_rack_runtime fails on JRuby due to timing
  2010-01-18 17:17     ` Charles Oliver Nutter
@ 2010-02-08 19:38       ` Ryan Tomayko
  0 siblings, 0 replies; 5+ messages in thread
From: Ryan Tomayko @ 2010-02-08 19:38 UTC (permalink / raw)
  To: rack-devel

On Mon, Jan 18, 2010 at 9:17 AM, Charles Oliver Nutter
<headius@headius.com> wrote:
> On Mon, Jan 18, 2010 at 12:59 AM, Christian Neukirchen
> <chneukirchen@gmail.com> wrote:
>> On Mon, Jan 18, 2010 at 7:38 AM, Ryan Tomayko <r@tomayko.com> wrote:
>>> Perhaps changing the assertion to be:
>>>
>>>    Float(response[1]['X-Runtime-All']).should >=
>>> Float(response[1]['X-Runtime-App'])
>>>
>>> ... or removing the assertion entirely.
>>
>> ... or introducing/moving a second sleep.
>
> I made the following change on my (temporary) rack fork, which helps
> ensure the times are long enough to be measurable:
>
> http://github.com/headius/rack/commit/fb0a7378852b678315b403eb2061da73b4478a37
>
> It's a little hacky, but it works well enough. Timing tests are
> obviously hard to get right in any case.

Applied this to rack/master along with a fix for the content-length
issue. Sorry for the delay.

Thanks,
Ryan

^ permalink raw reply	[flat|nested] 5+ messages in thread

end of thread, other threads:[~2010-02-08 19:38 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2010-01-17 18:20 Rack test spec_rack_runtime fails on JRuby due to timing Charles Oliver Nutter
2010-01-18  6:38 ` Ryan Tomayko
2010-01-18  6:59   ` Christian Neukirchen
2010-01-18 17:17     ` Charles Oliver Nutter
2010-02-08 19:38       ` Ryan Tomayko

Code repositories for project(s) associated with this inbox:

	https://80x24.org/mirrors/rack.git

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).