time.time() under load between two machines

[kwharrigan]

I am working on some code using python and a distributed system. Some
particular message is sent on one machine (with a timestamp logged) and
after the message is received, a timestamp is made. I am having
problems with negative latencies happening under intense CPU load.
There is ntp sync happening so the machines should be very well in
sync. Example:

machine1
----

sendTime = time.time()
<Call to send message>

machine2
---

<Got a message>
recvTime = time.time()

Latency = recvTime-sendTime is NEGATIVE

Is it possible that the CPU load is affecting the accuracy of the
time.time() call, or that the relative difference in CPU load between
the machines is causing this delta inaccuracy? Any help would be
appreciated.

Kyle Harrigan

 

[Michael Hoffman]

I am working on some code using python and a distributed system. Some
particular message is sent on one machine (with a timestamp logged) and
after the message is received, a timestamp is made. I am having
problems with negative latencies happening under intense CPU load.

How negative are we talking about? What platforms are you using?

 

[kwharrigan]

At least on the order of .1-1 seconds. Both platforms are Windows XP
SP2.

 

[Andreas Kostyrka]

I've just noticed that you didn't mention any details like OS, versions,
network infrastructure. You do not mention either how large the difference
is.

Andreas

 

[kwharrigan]

Python version is 2.3.3. Using Windows XP SP2 as stated above.
Network infrastructure is really irrelevant, what I'm attempting to
figure out is how a time.time() call on another machine that occurs
AFTER a message is received could occur before the message is actually
sent.

 

[Jeff Epler]

What makes you believe that the two machines' clocks are perfectly
synchronized? If they're not, it easily explains the result.

I wrote a simple client/server program similar to what you described.
Running on two RedHat 9 machines on a local network, I generally
observed a time delta of 2ms (compared to typical 0.17ms latency
reported by "ping"), never in a negative direction. These machines
times are synchronized by ntpd from the package ntp-4.1.2-0.rc1.2.

My program can be run like this:
rsh otherhost python timely.py -s | python timely.py -r
the values printed are the difference between the remote time before the
message is sent and the local time after the message is received.

You mention using Windows. I don't know whether Windows machines by
default use anything as sophisticated as ntpd to keep their clocks
accurate.

Whatever is going on in your case, I suspect it is the operating system,
not Python.

Jeff

import os, sys, time

def serve():
while 1:
data = struct.pack("!d", time.time())
os.write(1, data)
time.sleep(1)

def recv(fileno):
while 1:
data = struct.unpack("!d", os.read(fileno, 8))[0]
now = time.time()
print now - data

if sys.argv[1] == "-s":
serve()
else:
recv(0)

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.2.1 (GNU/Linux)

iD8DBQFC4Qq7Jd01MZaTXX0RAqYWAJ9wQHk+yHz/KiJXJxsq/iHh6XJxvgCdEwwP
uTtXBAUbvjRHpc5aHHsDwXU=
=8qHY
-----END PGP SIGNATURE-----

 

[kwharrigan]

I am seeing negative latencies of up to 1 second. I am using ntp to
synchronize both machines at an interval of 2 seconds, so the clocks
should be very much in sync (and are from what I have observed). I
agree that it is probably OS, perhaps I should hop over to a Microsoft
newsgroup and pose the question, although I'm sure they will find a way
to blame it on Python.

 

[Tim Peters]

[[email protected]]

I am seeing negative latencies of up to 1 second. I am using ntp to
synchronize both machines at an interval of 2 seconds, so the clocks
should be very much in sync (and are from what I have observed). I
agree that it is probably OS, perhaps I should hop over to a Microsoft
newsgroup and pose the question, although I'm sure they will find a way
to blame it on Python.

That won't be easy <wink>. This is how Python computes time.time() on
Windows (it's C code, of course):

struct timeb t;
ftime(&t);
return (double)t.time + (double)t.millitm * (double)0.001;

`ftime()` there is from Microsoft's C library:

<http://msdn.microsoft.com/library/default.asp?url=/library/en-us/vclib/html/_CRT__ftime.asp>

IOW, Python basically returns exactly what MS's ftime() returns, after
converting it to a double-precision float.

 

[Mike Meyer]

I am seeing negative latencies of up to 1 second. I am using ntp to
synchronize both machines at an interval of 2 seconds, so the clocks
should be very much in sync (and are from what I have observed). I
agree that it is probably OS, perhaps I should hop over to a Microsoft
newsgroup and pose the question, although I'm sure they will find a way
to blame it on Python.

We're getting off topic here, but what are the two machines ntp
syncing to? Specifically, is one syncing to the other, or are they
both syncing to the same external source, or - worst case - are they
syncing to different external sources? Have you checked the drift file
on the two machines?

<mike