JRuby

Time.new inconsitencies

Details

  • Type: Bug Bug
  • Status: Closed Closed
  • Priority: Critical Critical
  • Resolution: Fixed
  • Affects Version/s: JRuby 1.1.2
  • Fix Version/s: JRuby 1.1.3
  • Component/s: None
  • Labels:
    None
  • Environment:
    JDK6 (1.6.0_06) and JDK5 (1.5.0_07) on Solaris 10 (32bit)
  • Testcase included:
    yes
  • Number of attachments :
    0

Description

One of our rails tests kept on failing intermittently. After some poking around I noticed that it this is caused by Time.now. This test case describes the problem the best:

while (true) do        
  t1=Time.now            
  t2=Time.now            
  if t1 > t2
    puts "\n Time shift occurred! #{t1.to_i}.#{t1.usec} > #{t2.to_i}.#{t2.usec}"
    break
  else
    print "."
  end
end

$ jruby test.rb
....
1214278834.151719 > 1214278834.151182

I tried to run the same script on MacOSX (JDK5 and 6) and things work properly, so I wonder if this isn't actually a problem in the Solaris version of JDK.

Issue Links

relates to

Improvement - An improvement or enhancement to an existing feature or task. JRUBY-2788 Make Time.now monotonically increasing

  • Minor - Minor loss of function, or other problem where easy workaround is present.
  • Closed - The issue is considered finished, the resolution is correct. Issues which are not closed can be reopened.

Activity

Ascending order - Click to sort in descending order
Hide
Permalink
Vladimir Sizikov added a comment -

Reproducible on Linux for both MRI and JRuby!

But it takes much more iterations for MRI to find the "time shift" , while JRuby takes just a couple of iterations.

Tried with MRI 1.8.6, 1.8.7, 1.9, all fail. JRuby from trunk.

Show
Vladimir Sizikov added a comment - Reproducible on Linux for both MRI and JRuby! But it takes much more iterations for MRI to find the "time shift" , while JRuby takes just a couple of iterations. Tried with MRI 1.8.6, 1.8.7, 1.9, all fail. JRuby from trunk.
Hide
Permalink
Igor Minar added a comment -

Interesting on MacOSX both JRuby and RMI (1.8.6) work just fine.

Show
Igor Minar added a comment - Interesting on MacOSX both JRuby and RMI (1.8.6) work just fine.
Hide
Permalink
Charles Oliver Nutter added a comment -

If this affects both JRuby and MRI the same, I'm inclined to close this as WONTFIX.

Show
Charles Oliver Nutter added a comment - If this affects both JRuby and MRI the same, I'm inclined to close this as WONTFIX.
Hide
Permalink
Igor Minar added a comment -

I can't reproduce this with MRI [1] on Solaris 10 only with JRuby.

I respectfully disagree with this one being closed as WONTFIX even if it was a bug in MRI. This is a really nasty issue and the fact that a fundamental assumption that the current time can only increment doesn't apply to Ruby is a major flaw. Even if MRI didn't fix it, I'd expect JRuby community to feel that this is something that JRuby should fix because that's the right thing to do (similarly to implementing real threading in JRuby vs green threads in MRI).

[1] ruby 1.8.6 (2007-09-23 patchlevel 110) [i386-solaris2.8] from blastwave.org

Show
Igor Minar added a comment - I can't reproduce this with MRI [1] on Solaris 10 only with JRuby. I respectfully disagree with this one being closed as WONTFIX even if it was a bug in MRI. This is a really nasty issue and the fact that a fundamental assumption that the current time can only increment doesn't apply to Ruby is a major flaw. Even if MRI didn't fix it, I'd expect JRuby community to feel that this is something that JRuby should fix because that's the right thing to do (similarly to implementing real threading in JRuby vs green threads in MRI). [1] ruby 1.8.6 (2007-09-23 patchlevel 110) [i386-solaris2.8] from blastwave.org
Hide
Permalink
Charles Oliver Nutter added a comment -

Igor: I guess I'm at a loss for how to fix this. The second call is happening after the first, so I'm not sure how we can do anything to improve it. Do you have any suggestions?

Show
Charles Oliver Nutter added a comment - Igor: I guess I'm at a loss for how to fix this. The second call is happening after the first, so I'm not sure how we can do anything to improve it. Do you have any suggestions?
Hide
Permalink
Vladimir Sizikov added a comment -

I agree, ever increasing values is one of Time core fundamental properties, and we need to fix this one way or another.

Will try.

Show
Vladimir Sizikov added a comment - I agree, ever increasing values is one of Time core fundamental properties, and we need to fix this one way or another. Will try.
Hide
Permalink
Vladimir Sizikov added a comment -

Marking for 1.1.3

Show
Vladimir Sizikov added a comment - Marking for 1.1.3
Hide
Permalink
Vladimir Sizikov added a comment -

Ok, this turned out MUCH more tricky, beyond my wildest expectations.

1. There is a bug in JRuby, and I'm going to fix that.

2. BUT, both MRI and Java use 'gettimeofday' syscalls to obtain the time or System.nanoTime() in Java. The assumption is that gettimeofday always returns increasing values – this is just an assumption, not 100% accurate on all different OSes.

For example, on my Linux box, I see that gettimeofday sometimes returns decreasing value, and I see that java's nanoTime(), that uses gettimeofday internally, also returns decreasing value!

There are also at least 3 different Linux kernel bugs related to gettimeofday weirdness on different kernel versions.

Long story short, we won't add any hacks and tricks to work around those behaviours exhibited by the OS itself. If the OS allows to return non-increasing values from gettimeofday, so be it.

Show
Vladimir Sizikov added a comment - Ok, this turned out MUCH more tricky, beyond my wildest expectations. 1. There is a bug in JRuby, and I'm going to fix that. 2. BUT , both MRI and Java use 'gettimeofday' syscalls to obtain the time or System.nanoTime() in Java. The assumption is that gettimeofday always returns increasing values – this is just an assumption, not 100% accurate on all different OSes. For example, on my Linux box, I see that gettimeofday sometimes returns decreasing value, and I see that java's nanoTime(), that uses gettimeofday internally, also returns decreasing value! There are also at least 3 different Linux kernel bugs related to gettimeofday weirdness on different kernel versions. Long story short, we won't add any hacks and tricks to work around those behaviours exhibited by the OS itself. If the OS allows to return non-increasing values from gettimeofday, so be it.
Hide
Permalink
Vladimir Sizikov added a comment -

Fixed in rev. r7154 on trunk.

So, if the OS returns always-incrementing values, JRuby should have that too now.

The supplied test passes 100% now on Windows for me.

Show
Vladimir Sizikov added a comment - Fixed in rev. r7154 on trunk. So, if the OS returns always-incrementing values, JRuby should have that too now. The supplied test passes 100% now on Windows for me.
Hide
Permalink
Vladimir Sizikov added a comment - - edited

These two issues are related.

I noticed the decreasing results out of gettimeofday and System.nanoTime() on my Ubuntu 8.04 (running inside VirtualBox on Windows!).

When tried on Fedora Core 6 on real hardware, I couldn't reproduce that strange behavior.

Asking Google, it seems that there are gettimeofday related bugs in some Linux kernels though...

Show
Vladimir Sizikov added a comment - - edited These two issues are related. I noticed the decreasing results out of gettimeofday and System.nanoTime() on my Ubuntu 8.04 (running inside VirtualBox on Windows!). When tried on Fedora Core 6 on real hardware, I couldn't reproduce that strange behavior. Asking Google, it seems that there are gettimeofday related bugs in some Linux kernels though...
Hide
Permalink
Igor Minar added a comment -

Vladimir you rock! I can confirm that the bug is now fixed. I let the code above run on my solaris machine for 24 hours and no "time-shifts" occurred (before it would take 5-20 iterations).

btw I was testing the code with RMI a bit more and I did reproduce the problem, but it took about 4 hours of continuous execution of the loop for it to show up.

Anyway, thanks a lot!

Show
Igor Minar added a comment - Vladimir you rock! I can confirm that the bug is now fixed. I let the code above run on my solaris machine for 24 hours and no "time-shifts" occurred (before it would take 5-20 iterations ). btw I was testing the code with RMI a bit more and I did reproduce the problem, but it took about 4 hours of continuous execution of the loop for it to show up. Anyway, thanks a lot!

People

  • Assignee:
    Vladimir Sizikov
    Reporter:
    Igor Minar
Vote (0)
Watch (5)

Dates

  • Created:
    Updated:
    Resolved: