Propose: System.currentTimeNanos()

[juliusdavies]

[Sorry if this gets double-posted....!]

Hi,

I opened an enhancement in Sun's bug database to ask for
System.currentTimeNanos():

http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6709908

Normally I wouldn't harrass a random mailing list with my private
ravings, but the "Evaluation" section in the bug points back to this
list!  After reading the thread in question
(http://www.nabble.com/High-resolution-timers-and-JSR-310-td17302683.html),
I did not think the currentTimeNanos() idea was actually addressed.
The idea is *not* to compose System.currentTimeMillis() and
System.nanoTime().  Composing those two methods just doesn't work, and
never will.

Instead the idea is to extend System.currentTimeMillis() a little - to
nanosecond precision (when possible) - by returning a 2-element long
array, and calling it System.getCurrentTimeNanos().  It appears that
all the major OS's *except* Windows support this, and it can be
reasonably faked out on Windows, even, in a single JNI call.

In other words, the idea is to stop truncating what the OS is already
giving java when we call System.currentMillis().

I invite people to download the zip file and take a look:

http://juliusdavies.ca/nanotime/nanotime.zip

It builds on unix/mac-os-x with no problem.  On windows in compiles
nicely if you have cygwin, gcc, and mingw.


Here's a cut & paste from the Sun ticket (with minor edits on my part
for clarity, as well as mention of the 2038 problem that might lurk
behind gettimeofday()):

----------------------------------------------
JUSTIFICATION :
Solaris and Linux already support nanosecond precision thanks to
clock_gettime(CLOCK_REALTIME).  System.currentTimeMillis() already
uses that, but it would be nice to not truncate the nanoseconds.  The
situation on Mac OSX is a little different, since only gettimeofday()
is available, which gives microseconds (possible 32bit issues - e.g.
infamous 2038?).  But it's still an improvement.

Of course on Windows all timing information between the 10ms
granularity is quasi-fictional, but for figuring out order-of-events
in a log, a "high-resolution clock simulator" on windows would still
be useful.

EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
System.currentTimeNanos() would return a two-element long array
containing {seconds, nanos} since epoch.  The time returned would be
as accurate as the operating system could provide (e.g. nanos would be
micros * 1000 on Mac OSX).

On Windows the time returned would be an approximation, since Windows
cannot accurately report time changes faster than 10ms apart.

---------- BEGIN SOURCE ----------
Here is a prototype java library which illustrates the idea:

http://juliusdavies.ca/nanotime/

Download "nanotime.jar" and type:

java -jar nanotime.jar

It will print out 1 timing using System.currentTimeMillis(), and 10
timings using something like currentTimeNanos():

2008-05-14/17:08:15.940000000/PDT JavaTime
2008-05-14/17:08:15.940787900/PDT NativeTime
2008-05-14/17:08:15.943128363/PDT NativeTime
2008-05-14/17:08:15.943134021/PDT NativeTime
2008-05-14/17:08:15.943138875/PDT NativeTime
2008-05-14/17:08:15.943149498/PDT NativeTime
2008-05-14/17:08:15.943154580/PDT NativeTime
2008-05-14/17:08:15.943158845/PDT NativeTime
2008-05-14/17:08:15.943163060/PDT NativeTime
2008-05-14/17:08:15.943167074/PDT NativeTime
2008-05-14/17:08:15.943171148/PDT NativeTime

At this time the jar file can be run on Java 1.3, 1.4, 5, 6 on the
following platforms:

linux-amd64
linux-ppc (IBM's JDK)
linux-x86
mac-x86
solaris-sparc
win32


You need write-permission to ${user.home} to run this jar file.  It
automatically extracts a native library to ${user.home}/.libjnt/ for
the current platform.


Here is the JNI C code that asks the Operating System for the current time:

http://juliusdavies.ca/nanotime/src/native/mac_nano.c
http://juliusdavies.ca/nanotime/src/native/unix_nano.c
http://juliusdavies.ca/nanotime/src/native/win_nano.c


--
yours,

Julius Davies
250-592-2284 (Home)
250-893-4579 (Mobile)
http://juliusdavies.ca/
_______________________________________________
Concurrency-interest mailing list
Concurrency-interest@...
http://altair.cs.oswego.edu/mailman/listinfo/concurrency-interest

[David Holmes-3]

Hello Julius,

So what you are basically asking for is to have a method that exposes
clock_gettime(CLOCK_REALTIME) at whatever resolution the underlying OS
provides - with an understanding that Windows probably won't be able to do
better than the 10ms default time-of-day update. This method would represent
time-since-the-epoch in nanoseconds, and would also track changes in
wall-clock time (ntp updates, DST changes etc).

Is that the semantics you are looking for?

I ran some tests and modern Linux systems (2.6.21+) and Solaris seem to have
an update rate of a few microseconds for CLOCK_REALTIME - which is good. I
don't know how well it tracks tod changes. Older linux systems, eg 2.4
series seem to be stuck with the 10ms update rate. I don't know if the good
resolution on Linux is dependent on the fairly recent hrtimers work done in
the kernel - I don't have a huge range of systems to test on.

Regarding the return value, I don't see why we need anything other than a
long. A Java long can hold sufficient nanoseconds to represent 292+ years,
so there is no concern about overflow.

I still wonder exactly what people would use this time information for - it
would be necessary, but not sufficient to allow comparison of timestamps
across systems. I also wonder how well behaved clock_gettime is on MP
systems.

Cheers,
David Holmes

> -----Original Message-----
> From: concurrency-interest-bounces@...
> [mailto:concurrency-interest-bounces@...]On Behalf Of Julius
> Davies
> Sent: Wednesday, 25 June 2008 10:13 AM
> To: concurrency-interest@...
> Subject: [concurrency-interest] Propose: System.currentTimeNanos()
>
>
> [Sorry if this gets double-posted....!]
>
> Hi,
>
> I opened an enhancement in Sun's bug database to ask for
> System.currentTimeNanos():
>
> http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6709908
>
> Normally I wouldn't harrass a random mailing list with my private
> ravings, but the "Evaluation" section in the bug points back to this
> list!  After reading the thread in question
> (http://www.nabble.com/High-resolution-timers-and-JSR-310-td173026
> 83.html),
> I did not think the currentTimeNanos() idea was actually addressed.
> The idea is *not* to compose System.currentTimeMillis() and
> System.nanoTime().  Composing those two methods just doesn't work, and
> never will.
>
> Instead the idea is to extend System.currentTimeMillis() a little - to
> nanosecond precision (when possible) - by returning a 2-element long
> array, and calling it System.getCurrentTimeNanos().  It appears that
> all the major OS's *except* Windows support this, and it can be
> reasonably faked out on Windows, even, in a single JNI call.
>
> In other words, the idea is to stop truncating what the OS is already
> giving java when we call System.currentMillis().
>
> I invite people to download the zip file and take a look:
>
> http://juliusdavies.ca/nanotime/nanotime.zip
>
> It builds on unix/mac-os-x with no problem.  On windows in compiles
> nicely if you have cygwin, gcc, and mingw.
>
>
> Here's a cut & paste from the Sun ticket (with minor edits on my part
> for clarity, as well as mention of the 2038 problem that might lurk
> behind gettimeofday()):
>
> ----------------------------------------------
> JUSTIFICATION :
> Solaris and Linux already support nanosecond precision thanks to
> clock_gettime(CLOCK_REALTIME).  System.currentTimeMillis() already
> uses that, but it would be nice to not truncate the nanoseconds.  The
> situation on Mac OSX is a little different, since only gettimeofday()
> is available, which gives microseconds (possible 32bit issues - e.g.
> infamous 2038?).  But it's still an improvement.
>
> Of course on Windows all timing information between the 10ms
> granularity is quasi-fictional, but for figuring out order-of-events
> in a log, a "high-resolution clock simulator" on windows would still
> be useful.
>
> EXPECTED VERSUS ACTUAL BEHAVIOR :
> EXPECTED -
> System.currentTimeNanos() would return a two-element long array
> containing {seconds, nanos} since epoch.  The time returned would be
> as accurate as the operating system could provide (e.g. nanos would be
> micros * 1000 on Mac OSX).
>
> On Windows the time returned would be an approximation, since Windows
> cannot accurately report time changes faster than 10ms apart.
>
> ---------- BEGIN SOURCE ----------
> Here is a prototype java library which illustrates the idea:
>
> http://juliusdavies.ca/nanotime/
>
> Download "nanotime.jar" and type:
>
> java -jar nanotime.jar
>
> It will print out 1 timing using System.currentTimeMillis(), and 10
> timings using something like currentTimeNanos():
>
> 2008-05-14/17:08:15.940000000/PDT JavaTime
> 2008-05-14/17:08:15.940787900/PDT NativeTime
> 2008-05-14/17:08:15.943128363/PDT NativeTime
> 2008-05-14/17:08:15.943134021/PDT NativeTime
> 2008-05-14/17:08:15.943138875/PDT NativeTime
> 2008-05-14/17:08:15.943149498/PDT NativeTime
> 2008-05-14/17:08:15.943154580/PDT NativeTime
> 2008-05-14/17:08:15.943158845/PDT NativeTime
> 2008-05-14/17:08:15.943163060/PDT NativeTime
> 2008-05-14/17:08:15.943167074/PDT NativeTime
> 2008-05-14/17:08:15.943171148/PDT NativeTime
>
> At this time the jar file can be run on Java 1.3, 1.4, 5, 6 on the
> following platforms:
>
> linux-amd64
> linux-ppc (IBM's JDK)
> linux-x86
> mac-x86
> solaris-sparc
> win32
>
>
> You need write-permission to ${user.home} to run this jar file.  It
> automatically extracts a native library to ${user.home}/.libjnt/ for
> the current platform.
>
>
> Here is the JNI C code that asks the Operating System for the
> current time:
>
> http://juliusdavies.ca/nanotime/src/native/mac_nano.c
> http://juliusdavies.ca/nanotime/src/native/unix_nano.c
> http://juliusdavies.ca/nanotime/src/native/win_nano.c
>
>
> --
> yours,
>
> Julius Davies
> 250-592-2284 (Home)
> 250-893-4579 (Mobile)
> http://juliusdavies.ca/
> _______________________________________________
> Concurrency-interest mailing list
> Concurrency-interest@...
> http://altair.cs.oswego.edu/mailman/listinfo/concurrency-interest

_______________________________________________
Concurrency-interest mailing list
Concurrency-interest@...
http://altair.cs.oswego.edu/mailman/listinfo/concurrency-interest

[juliusdavies]

Hi, David,

Thanks so much for looking at this.  You've got it!  Expose
clock_gettime(CLOCK_REALTIME)!  (Or, in the worst case,
gettimeofday()).  I would really like that.

>
> So what you are basically asking for is to have a method that exposes
> clock_gettime(CLOCK_REALTIME) at whatever resolution the underlying OS
> provides - with an understanding that Windows probably won't be able to do
> better than the 10ms default time-of-day update. This method would represent
> time-since-the-epoch in nanoseconds, and would also track changes in
> wall-clock time (ntp updates, DST changes etc).

Yes!  (Do you think the windows "hires simulator" is worth bothering
with?  It does have some weird behaviour when NTP is slewing, but how
often does that happen?

Here's an example on Windows with clock slew (scroll down a little):
https://jsr-310.dev.java.net/servlets/ReadMsg?list=dev&msgNo=1274

Here's the "hires simulator" code:
http://juliusdavies.ca/nanotime/src/native/win_nano.c

>
> I ran some tests and modern Linux systems (2.6.21+) and Solaris seem to have
> an update rate of a few microseconds for CLOCK_REALTIME - which is good. I
> don't know how well it tracks tod changes. Older linux systems, eg 2.4
> series seem to be stuck with the 10ms update rate. I don't know if the good
> resolution on Linux is dependent on the fairly recent hrtimers work done in
> the kernel - I don't have a huge range of systems to test on.
>

I'm getting the same results on amd64 linux and sparc solaris:  about
1 micro.  I'm curious if multi-processor / multi-core would allow
those 1 micro reads to be staggered such that throughput was more like
1 read every 500 nanos.  For example:

CPU1  2500 nanos  CPU2 3000 nanos
CPU1  3500 nanos  CPU2 4000 nanos
CPU1  4500 nanos  CPU2 5000 nanos

What I'm really getting at is this:  is it really an update rate of 1
micro, or is the update rate really good, and the problem is that the
code itself takes 1 micro to execute?  If that's the case, maybe the
update rate is actually in the nano range, and even on a 64 core
system, the timestamps will tend to never be unique!?  (e.g. within
1000/64 nanos of each other)  That would be awesome!

I imagine clock_gettime(CLOCK_REALTIME) tracks TOD changes quite well
- doesn't System.currentTimeMillis() already use it?


> Regarding the return value, I don't see why we need anything other than a
> long. A Java long can hold sufficient nanoseconds to represent 292+ years,
> so there is no concern about overflow.
>

I think a 2-element long array is the way to go.  JSR-310 is already
taking that approach (well... long + int).  Clock_gettime() also does
the same thing (the timespec struct is also essentially long + int,
a.k.a. long long + long).  I guess we save 12 bytes by going with just
one long?  Is it worth it?

> I still wonder exactly what people would use this time information for - it
> would be necessary, but not sufficient to allow comparison of timestamps
> across systems. I also wonder how well behaved clock_gettime is on MP
> systems.
>

Here's my usecase:

http://juliusdavies.ca/logging.html#timestamps

In addition to that, nanosecond precision makes it much more possible
for log timestamps to become part of a primary key in a natural way
that preserves chronology.

It's not really about "do we need nanoseconds."  It's more about "how
can we track order of events on a heavily loaded multi-core system?"
I think it's obvious that millis is not good enough.  Micros is
probably good enough.  Might as well overshoot with nanos, to be safe.

As for distributed systems... well, you can't even assume clocks are
set to the same century.  It's just not applicable to this discussion.
 It's just order-of-events on a single system.... err... well, a
single-clock, whatever that might be.


> Cheers,
> David Holmes
>

Again, thanks for reading!  If you think it's a good idea, would you
mind commenting over at the bug?

http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6709908


yours,

Julius

ps.  when it comes to java timestamps, all roads lead to
http://blogs.sun.com/dholmes/entry/inside_the_hotspot_vm_clocks .
Thanks for your original blog post.  It was very helpful.

>> -----Original Message-----
>> From: concurrency-interest-bounces@...
>> [mailto:concurrency-interest-bounces@...]On Behalf Of Julius
>> Davies
>> Sent: Wednesday, 25 June 2008 10:13 AM
>> To: concurrency-interest@...
>> Subject: [concurrency-interest] Propose: System.currentTimeNanos()
>>
>>
>> [Sorry if this gets double-posted....!]
>>
>> Hi,
>>
>> I opened an enhancement in Sun's bug database to ask for
>> System.currentTimeNanos():
>>
>> http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6709908
>>
>> Normally I wouldn't harrass a random mailing list with my private
>> ravings, but the "Evaluation" section in the bug points back to this
>> list!  After reading the thread in question
>> (http://www.nabble.com/High-resolution-timers-and-JSR-310-td173026
>> 83.html),
>> I did not think the currentTimeNanos() idea was actually addressed.
>> The idea is *not* to compose System.currentTimeMillis() and
>> System.nanoTime().  Composing those two methods just doesn't work, and
>> never will.
>>
>> Instead the idea is to extend System.currentTimeMillis() a little - to
>> nanosecond precision (when possible) - by returning a 2-element long
>> array, and calling it System.getCurrentTimeNanos().  It appears that
>> all the major OS's *except* Windows support this, and it can be
>> reasonably faked out on Windows, even, in a single JNI call.
>>
>> In other words, the idea is to stop truncating what the OS is already
>> giving java when we call System.currentMillis().
>>
>> I invite people to download the zip file and take a look:
>>
>> http://juliusdavies.ca/nanotime/nanotime.zip
>>
>> It builds on unix/mac-os-x with no problem.  On windows in compiles
>> nicely if you have cygwin, gcc, and mingw.
>>
>>
>> Here's a cut & paste from the Sun ticket (with minor edits on my part
>> for clarity, as well as mention of the 2038 problem that might lurk
>> behind gettimeofday()):
>>
>> ----------------------------------------------
>> JUSTIFICATION :
>> Solaris and Linux already support nanosecond precision thanks to
>> clock_gettime(CLOCK_REALTIME).  System.currentTimeMillis() already
>> uses that, but it would be nice to not truncate the nanoseconds.  The
>> situation on Mac OSX is a little different, since only gettimeofday()
>> is available, which gives microseconds (possible 32bit issues - e.g.
>> infamous 2038?).  But it's still an improvement.
>>
>> Of course on Windows all timing information between the 10ms
>> granularity is quasi-fictional, but for figuring out order-of-events
>> in a log, a "high-resolution clock simulator" on windows would still
>> be useful.
>>
>> EXPECTED VERSUS ACTUAL BEHAVIOR :
>> EXPECTED -
>> System.currentTimeNanos() would return a two-element long array
>> containing {seconds, nanos} since epoch.  The time returned would be
>> as accurate as the operating system could provide (e.g. nanos would be
>> micros * 1000 on Mac OSX).
>>
>> On Windows the time returned would be an approximation, since Windows
>> cannot accurately report time changes faster than 10ms apart.
>>
>> ---------- BEGIN SOURCE ----------
>> Here is a prototype java library which illustrates the idea:
>>
>> http://juliusdavies.ca/nanotime/
>>
>> Download "nanotime.jar" and type:
>>
>> java -jar nanotime.jar
>>
>> It will print out 1 timing using System.currentTimeMillis(), and 10
>> timings using something like currentTimeNanos():
>>
>> 2008-05-14/17:08:15.940000000/PDT JavaTime
>> 2008-05-14/17:08:15.940787900/PDT NativeTime
>> 2008-05-14/17:08:15.943128363/PDT NativeTime
>> 2008-05-14/17:08:15.943134021/PDT NativeTime
>> 2008-05-14/17:08:15.943138875/PDT NativeTime
>> 2008-05-14/17:08:15.943149498/PDT NativeTime
>> 2008-05-14/17:08:15.943154580/PDT NativeTime
>> 2008-05-14/17:08:15.943158845/PDT NativeTime
>> 2008-05-14/17:08:15.943163060/PDT NativeTime
>> 2008-05-14/17:08:15.943167074/PDT NativeTime
>> 2008-05-14/17:08:15.943171148/PDT NativeTime
>>
>> At this time the jar file can be run on Java 1.3, 1.4, 5, 6 on the
>> following platforms:
>>
>> linux-amd64
>> linux-ppc (IBM's JDK)
>> linux-x86
>> mac-x86
>> solaris-sparc
>> win32
>>
>>
>> You need write-permission to ${user.home} to run this jar file.  It
>> automatically extracts a native library to ${user.home}/.libjnt/ for
>> the current platform.
>>
>>
>> Here is the JNI C code that asks the Operating System for the
>> current time:
>>
>> http://juliusdavies.ca/nanotime/src/native/mac_nano.c
>> http://juliusdavies.ca/nanotime/src/native/unix_nano.c
>> http://juliusdavies.ca/nanotime/src/native/win_nano.c
>>
>>
>> --
>> yours,
>>
>> Julius Davies
>> 250-592-2284 (Home)
>> 250-893-4579 (Mobile)
>> http://juliusdavies.ca/
>> _______________________________________________
>> Concurrency-interest mailing list
>> Concurrency-interest@...
>> http://altair.cs.oswego.edu/mailman/listinfo/concurrency-interest
>
>

--
yours,

Julius Davies
250-592-2284 (Home)
250-893-4579 (Mobile)
http://juliusdavies.ca/
_______________________________________________
Concurrency-interest mailing list
Concurrency-interest@...
http://altair.cs.oswego.edu/mailman/listinfo/concurrency-interest

[David Holmes-3]

Hi Julius,

> Thanks so much for looking at this.  You've got it!  Expose
> clock_gettime(CLOCK_REALTIME)!  (Or, in the worst case,
> gettimeofday()).  I would really like that.

Doesn't seem unreasonable. :)

> Yes!  (Do you think the windows "hires simulator" is worth bothering
> with?  It does have some weird behaviour when NTP is slewing, but how
> often does that happen?
>
> Here's an example on Windows with clock slew (scroll down a little):
> https://jsr-310.dev.java.net/servlets/ReadMsg?list=dev&msgNo=1274
>
> Here's the "hires simulator" code:
> http://juliusdavies.ca/nanotime/src/native/win_nano.c

The cost/benefit ratio takes a dive if you have to play these sorts of
tricks. And any attempt to convert from "cycles" to "time" is fraught with
peril unless you're certain you have a well behaved Windows that uses a
fixed-frequency time source.

Note of course that you could become an OpenJDK contributor and offer up
what you've already done. In these OpenSource days it's sometimes hard to
see what the path is for getting small API updates into the system - the
code ends up being the easy part.

> What I'm really getting at is this:  is it really an update rate of 1
> micro, or is the update rate really good, and the problem is that the
> code itself takes 1 micro to execute?  If that's the case, maybe the
> update rate is actually in the nano range, and even on a 64 core
> system, the timestamps will tend to never be unique!?  (e.g. within
> 1000/64 nanos of each other)  That would be awesome!

:) Undoubtedly the call itself takes some time. You'd have to delve into the
details of the OS and the hardware time source to determine what it's actual
update rate is. But you'll never be guaranteed unique values.

> I imagine clock_gettime(CLOCK_REALTIME) tracks TOD changes quite well
> - doesn't System.currentTimeMillis() already use it?

Nope. currentTimeMillis() uses gettimeofday(). It's a very old piece of
code. I should probably walk through the Solaris code sometime to see where
gettimeofday and clock_gettime meet up.

> I think a 2-element long array is the way to go.  JSR-310 is already
> taking that approach (well... long + int).  Clock_gettime() also does
> the same thing (the timespec struct is also essentially long + int,
> a.k.a. long long + long).  I guess we save 12 bytes by going with just
> one long?  Is it worth it?

Definitely! Dealing with an array is a PITA as far as I am concerned. I
think most people would take the array and turn it into a single value - so
lets do that for them. In the real-time Java spec there was obviously far
too much 'timespec' influence as they define time objects as a
(millis,nanos) pair and they are a real pain to deal with in my opinion -
the first thing I did (on a previous project) was to change the internal
representation to use a long. :)

Think of the simplest usecase: printing the value - you can't do
System.out.print(System.currentTimeNanos()); if it returns an array (well
you can but you won't see the timestamp :) ).

> Here's my usecase:
>
> http://juliusdavies.ca/logging.html#timestamps
>
> In addition to that, nanosecond precision makes it much more possible
> for log timestamps to become part of a primary key in a natural way
> that preserves chronology.

If you are only interested in comparative ordering then System.nanoTime will
give you as much 'uniqueness' as what we're discussing here. Seeing the date
can be useful, but if your timestamp tracks wall-clock time then your logs
are going to have duplication around DST changes. I suppose it's only once a
year that things get screwed up but someone still has to deal with that. And
ntp updates also mess things up. A logger could output a date +
System.nanoTime value which would aid correlation with wall-clock time while
still giving (modulo bugs!) a monotonic timestamp.

Just my 2c.

> Again, thanks for reading!  If you think it's a good idea, would you
> mind commenting over at the bug?
>
> http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6709908

I already added a new section to the evaluation.

> ps.  when it comes to java timestamps, all roads lead to
> http://blogs.sun.com/dholmes/entry/inside_the_hotspot_vm_clocks .
> Thanks for your original blog post.  It was very helpful.

Glad to hear it. It's getting a little dated now. And I never got around to
discussing Solaris or Linux. The sad thing is that what I did discover is
that you simply can't trust the OS to get it right - so many bugs ... at
least on x86. :(

Cheers,
David Holmes

_______________________________________________
Concurrency-interest mailing list
Concurrency-interest@...
http://altair.cs.oswego.edu/mailman/listinfo/concurrency-interest

[juliusdavies]

Hi, David,

Thanks for the reply!  I just have a tiny little note of interest.

I tried running four Java6 processes concurrently.

The 1 micro stayed the same.

But each call took 4 micros instead of 1 micro as it did before.
Throughput stayed the same even though there were 4 running JVM's
instead of 1, and latency increased.  I guess linux is the bottleneck
(64bit 2.6.23 dual-core turion laptop)?  Every nanosecond timestamp
was unique, but they were also all around 1 micro apart.  One last
thing:  performance for currentTimeMillis() went south in the exact
same way:  4 micros per call, instead of 1 micro.

Oh, and you're right:  I don't just want order-of-events.  I want
time-of-day, and then I want order-of-events for everything in the
same second (or log4j's best guess at order-of-events... there's a
whole other can of worms) - so yeah, a hybrid, just like you're
saying.  But having both millis() and the monotonic in the same line -
it does the job, but it's not very friendly for human eyes.  (And how
many zeroes should I pad nanoTime() with?)  (I will admit that sort -n
fixes the zero-padding problem).

The DST thing isn't a problem, because all good logs include TZ, or
GMT offset at the very least.  Or they're in UTC.  Or they use a
cheeky trick with a semi-colon:

(Here's the cheeky trick:)
https://jsr-310.dev.java.net/servlets/ReadMsg?list=dev&msgNo=1330



yours,

Julius




On Wed, Jun 25, 2008 at 12:22 AM, David Holmes <dcholmes@...> wrote:

> Hi Julius,
>
>> Thanks so much for looking at this.  You've got it!  Expose
>> clock_gettime(CLOCK_REALTIME)!  (Or, in the worst case,
>> gettimeofday()).  I would really like that.
>
> Doesn't seem unreasonable. :)
>
>> Yes!  (Do you think the windows "hires simulator" is worth bothering
>> with?  It does have some weird behaviour when NTP is slewing, but how
>> often does that happen?
>>
>> Here's an example on Windows with clock slew (scroll down a little):
>> https://jsr-310.dev.java.net/servlets/ReadMsg?list=dev&msgNo=1274
>>
>> Here's the "hires simulator" code:
>> http://juliusdavies.ca/nanotime/src/native/win_nano.c
>
> The cost/benefit ratio takes a dive if you have to play these sorts of
> tricks. And any attempt to convert from "cycles" to "time" is fraught with
> peril unless you're certain you have a well behaved Windows that uses a
> fixed-frequency time source.
>
> Note of course that you could become an OpenJDK contributor and offer up
> what you've already done. In these OpenSource days it's sometimes hard to
> see what the path is for getting small API updates into the system - the
> code ends up being the easy part.
>
>> What I'm really getting at is this:  is it really an update rate of 1
>> micro, or is the update rate really good, and the problem is that the
>> code itself takes 1 micro to execute?  If that's the case, maybe the
>> update rate is actually in the nano range, and even on a 64 core
>> system, the timestamps will tend to never be unique!?  (e.g. within
>> 1000/64 nanos of each other)  That would be awesome!
>
> :) Undoubtedly the call itself takes some time. You'd have to delve into the
> details of the OS and the hardware time source to determine what it's actual
> update rate is. But you'll never be guaranteed unique values.
>
>> I imagine clock_gettime(CLOCK_REALTIME) tracks TOD changes quite well
>> - doesn't System.currentTimeMillis() already use it?
>
> Nope. currentTimeMillis() uses gettimeofday(). It's a very old piece of
> code. I should probably walk through the Solaris code sometime to see where
> gettimeofday and clock_gettime meet up.
>
>> I think a 2-element long array is the way to go.  JSR-310 is already
>> taking that approach (well... long + int).  Clock_gettime() also does
>> the same thing (the timespec struct is also essentially long + int,
>> a.k.a. long long + long).  I guess we save 12 bytes by going with just
>> one long?  Is it worth it?
>
> Definitely! Dealing with an array is a PITA as far as I am concerned. I
> think most people would take the array and turn it into a single value - so
> lets do that for them. In the real-time Java spec there was obviously far
> too much 'timespec' influence as they define time objects as a
> (millis,nanos) pair and they are a real pain to deal with in my opinion -
> the first thing I did (on a previous project) was to change the internal
> representation to use a long. :)
>
> Think of the simplest usecase: printing the value - you can't do
> System.out.print(System.currentTimeNanos()); if it returns an array (well
> you can but you won't see the timestamp :) ).
>
>> Here's my usecase:
>>
>> http://juliusdavies.ca/logging.html#timestamps
>>
>> In addition to that, nanosecond precision makes it much more possible
>> for log timestamps to become part of a primary key in a natural way
>> that preserves chronology.
>
> If you are only interested in comparative ordering then System.nanoTime will
> give you as much 'uniqueness' as what we're discussing here. Seeing the date
> can be useful, but if your timestamp tracks wall-clock time then your logs
> are going to have duplication around DST changes. I suppose it's only once a
> year that things get screwed up but someone still has to deal with that. And
> ntp updates also mess things up. A logger could output a date +
> System.nanoTime value which would aid correlation with wall-clock time while
> still giving (modulo bugs!) a monotonic timestamp.
>
> Just my 2c.
>
>> Again, thanks for reading!  If you think it's a good idea, would you
>> mind commenting over at the bug?
>>
>> http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6709908
>
> I already added a new section to the evaluation.
>
>> ps.  when it comes to java timestamps, all roads lead to
>> http://blogs.sun.com/dholmes/entry/inside_the_hotspot_vm_clocks .
>> Thanks for your original blog post.  It was very helpful.
>
> Glad to hear it. It's getting a little dated now. And I never got around to
> discussing Solaris or Linux. The sad thing is that what I did discover is
> that you simply can't trust the OS to get it right - so many bugs ... at
> least on x86. :(
>
> Cheers,
> David Holmes
>
>

--
yours,

Julius Davies
250-592-2284 (Home)
250-893-4579 (Mobile)
http://juliusdavies.ca/
_______________________________________________
Concurrency-interest mailing list
Concurrency-interest@...
http://altair.cs.oswego.edu/mailman/listinfo/concurrency-interest

[David Holmes-3]

Hi Julius,

I could counter that as long as they are in order and will sort correctly,
then does it really matter what you see?

It just seems to me that having the timestamp be wall-clock time is more a
convenience than a necessity. And that "cheeky trick" for the DST extra hour
is pretty gross :) - and how does the formatter know whether a value is from
the original hour or the extra one? And there's still the more common
ntp-like adjustments that can cause things to go out of order.

Anyway plenty of things for others to comment on if we give them the chance.

Cheers,
David

> -----Original Message-----
> From: Julius Davies [mailto:juliusdavies@...]
> Sent: Wednesday, 25 June 2008 7:05 PM
> To: concurrency-interest@...; dholmes@...
> Subject: Re: [concurrency-interest] Propose: System.currentTimeNanos()
>
>
> Hi, David,
>
> Thanks for the reply!  I just have a tiny little note of interest.
>
> I tried running four Java6 processes concurrently.
>
> The 1 micro stayed the same.
>
> But each call took 4 micros instead of 1 micro as it did before.
> Throughput stayed the same even though there were 4 running JVM's
> instead of 1, and latency increased.  I guess linux is the bottleneck
> (64bit 2.6.23 dual-core turion laptop)?  Every nanosecond timestamp
> was unique, but they were also all around 1 micro apart.  One last
> thing:  performance for currentTimeMillis() went south in the exact
> same way:  4 micros per call, instead of 1 micro.
>
> Oh, and you're right:  I don't just want order-of-events.  I want
> time-of-day, and then I want order-of-events for everything in the
> same second (or log4j's best guess at order-of-events... there's a
> whole other can of worms) - so yeah, a hybrid, just like you're
> saying.  But having both millis() and the monotonic in the same line -
> it does the job, but it's not very friendly for human eyes.  (And how
> many zeroes should I pad nanoTime() with?)  (I will admit that sort -n
> fixes the zero-padding problem).
>
> The DST thing isn't a problem, because all good logs include TZ, or
> GMT offset at the very least.  Or they're in UTC.  Or they use a
> cheeky trick with a semi-colon:
>
> (Here's the cheeky trick:)
> https://jsr-310.dev.java.net/servlets/ReadMsg?list=dev&msgNo=1330
>
>
>
> yours,
>
> Julius
>
>
>
>
> On Wed, Jun 25, 2008 at 12:22 AM, David Holmes
> <dcholmes@...> wrote:
> > Hi Julius,
> >
> >> Thanks so much for looking at this.  You've got it!  Expose
> >> clock_gettime(CLOCK_REALTIME)!  (Or, in the worst case,
> >> gettimeofday()).  I would really like that.
> >
> > Doesn't seem unreasonable. :)
> >
> >> Yes!  (Do you think the windows "hires simulator" is worth bothering
> >> with?  It does have some weird behaviour when NTP is slewing, but how
> >> often does that happen?
> >>
> >> Here's an example on Windows with clock slew (scroll down a little):
> >> https://jsr-310.dev.java.net/servlets/ReadMsg?list=dev&msgNo=1274
> >>
> >> Here's the "hires simulator" code:
> >> http://juliusdavies.ca/nanotime/src/native/win_nano.c
> >
> > The cost/benefit ratio takes a dive if you have to play these sorts of
> > tricks. And any attempt to convert from "cycles" to "time" is
> fraught with
> > peril unless you're certain you have a well behaved Windows that uses a
> > fixed-frequency time source.
> >
> > Note of course that you could become an OpenJDK contributor and offer up
> > what you've already done. In these OpenSource days it's
> sometimes hard to
> > see what the path is for getting small API updates into the system - the
> > code ends up being the easy part.
> >
> >> What I'm really getting at is this:  is it really an update rate of 1
> >> micro, or is the update rate really good, and the problem is that the
> >> code itself takes 1 micro to execute?  If that's the case, maybe the
> >> update rate is actually in the nano range, and even on a 64 core
> >> system, the timestamps will tend to never be unique!?  (e.g. within
> >> 1000/64 nanos of each other)  That would be awesome!
> >
> > :) Undoubtedly the call itself takes some time. You'd have to
> delve into the
> > details of the OS and the hardware time source to determine
> what it's actual
> > update rate is. But you'll never be guaranteed unique values.
> >
> >> I imagine clock_gettime(CLOCK_REALTIME) tracks TOD changes quite well
> >> - doesn't System.currentTimeMillis() already use it?
> >
> > Nope. currentTimeMillis() uses gettimeofday(). It's a very old piece of
> > code. I should probably walk through the Solaris code sometime
> to see where
> > gettimeofday and clock_gettime meet up.
> >
> >> I think a 2-element long array is the way to go.  JSR-310 is already
> >> taking that approach (well... long + int).  Clock_gettime() also does
> >> the same thing (the timespec struct is also essentially long + int,
> >> a.k.a. long long + long).  I guess we save 12 bytes by going with just
> >> one long?  Is it worth it?
> >
> > Definitely! Dealing with an array is a PITA as far as I am concerned. I
> > think most people would take the array and turn it into a
> single value - so
> > lets do that for them. In the real-time Java spec there was
> obviously far
> > too much 'timespec' influence as they define time objects as a
> > (millis,nanos) pair and they are a real pain to deal with in my
> opinion -
> > the first thing I did (on a previous project) was to change the internal
> > representation to use a long. :)
> >
> > Think of the simplest usecase: printing the value - you can't do
> > System.out.print(System.currentTimeNanos()); if it returns an
> array (well
> > you can but you won't see the timestamp :) ).
> >
> >> Here's my usecase:
> >>
> >> http://juliusdavies.ca/logging.html#timestamps
> >>
> >> In addition to that, nanosecond precision makes it much more possible
> >> for log timestamps to become part of a primary key in a natural way
> >> that preserves chronology.
> >
> > If you are only interested in comparative ordering then
> System.nanoTime will
> > give you as much 'uniqueness' as what we're discussing here.
> Seeing the date
> > can be useful, but if your timestamp tracks wall-clock time
> then your logs
> > are going to have duplication around DST changes. I suppose
> it's only once a
> > year that things get screwed up but someone still has to deal
> with that. And
> > ntp updates also mess things up. A logger could output a date +
> > System.nanoTime value which would aid correlation with
> wall-clock time while
> > still giving (modulo bugs!) a monotonic timestamp.
> >
> > Just my 2c.
> >
> >> Again, thanks for reading!  If you think it's a good idea, would you
> >> mind commenting over at the bug?
> >>
> >> http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6709908
> >
> > I already added a new section to the evaluation.
> >
> >> ps.  when it comes to java timestamps, all roads lead to
> >> http://blogs.sun.com/dholmes/entry/inside_the_hotspot_vm_clocks .
> >> Thanks for your original blog post.  It was very helpful.
> >
> > Glad to hear it. It's getting a little dated now. And I never
> got around to
> > discussing Solaris or Linux. The sad thing is that what I did
> discover is
> > that you simply can't trust the OS to get it right - so many bugs ... at
> > least on x86. :(
> >
> > Cheers,
> > David Holmes
> >
> >
>
>
>
> --
> yours,
>
> Julius Davies
> 250-592-2284 (Home)
> 250-893-4579 (Mobile)
> http://juliusdavies.ca/

_______________________________________________
Concurrency-interest mailing list
Concurrency-interest@...
http://altair.cs.oswego.edu/mailman/listinfo/concurrency-interest