Hopefully somebody can add the last piece of this puzzle. My code didn't
work because I did make a silly mistake. The number of seconds since
EPOC is a large number but it also needs a high precision. Attempting to
put this value into a 32 bit float corrupts the least significant part
because 24 bits cannot hold that precision. Now Python floats are C
doubles and the calculation in timemodule.c is in doubles right back to
Python. Normally this retains the precision. For some inexplicable
reason when I make certain calls into this vendors SDK, ftime() is
getting precision problems and appears to be frozen as a result.
C, only supporting early binding cannot change the function referenced
at runtime so how the devil is it managing to do this.
On 08/05/2012 12:17, Bob Cowdery wrote:
Can anyone make sense of this.
I've looked over the Python timemodule.c again and it uses one of
gettimeofday(), ftime() or time(). The gettimeofday() is not available
on Windows so its going to use ftime() or time(). As time() only has a
resolution of 1 second and returns a long and I know Python
time.time() has a ms resolution it must be using ftime().
After going round the houses - a lot. I've made a trivially simple
extension that goes wrong. I can only think I must be doing something
incredibly stupid. Perhaps someone can put me out of my misery.
In the full app what happens is that it reports the correct time as
given by time() by gets the ms from somewhere also. When it goes wrong
it reports the same time as ftime().
Bob
>>> import mytime
>>> mytime.doTime()
TIME : 1336474857
FTIME secs 1336474880.000000
FTIME ms 0.601000
FTIME secs+ms 1336474880.601000
0
>>> mytime.doTime()
TIME : 1336474871
FTIME secs 1336474880.000000
FTIME ms 0.548000
FTIME secs+ms 1336474880.548000
0
>>> mytime.doTime()
TIME : 1336474897
FTIME secs 1336474880.000000
FTIME ms 0.007000
FTIME secs+ms 1336474880.007000
0
The extension just prints out the time as got from time() and ftime().
For a start the two do not agree on what the time is. Secondly ftime()
stops incrementing while the python session is running. If I start a
new session it will have incremented.
>>> import mytime
>>> mytime.doTime()
TIME : 1336475029
FTIME secs 1336475008.000000
FTIME ms 0.265000
FTIME secs+ms 1336475008.265000
0
Code and build file
================
#include "Python.h"
#include <sys/types.h>
#include <stdio.h>
#include <time.h>
#include <sys/timeb.h>
static struct timeb t;
static float secs = 0.0;
static float ms = 0.0;
static float both = 0.0;
static PyObject *doTime(
PyObject *self,
PyObject *args) {
time_t seconds;
seconds = time (NULL);
printf ("TIME : %ld\n", seconds);
ftime(&t);
secs = (float)t.time;
ms = (float)((float)t.millitm * 0.001);
printf("FTIME secs+ms %f\n", secs + ms);
return PyInt_FromLong((long)0);
}
static PyMethodDef pyInst_Methods[] = {
{"doTime",
doTime,
METH_VARARGS},
{NULL, NULL, 0, NULL}
};
#ifndef PyMODINIT_FUNC
#define PyMODINIT_FUNC void
#endif /* PyMODINIT_FUNC */
PyMODINIT_FUNC initmytime(void)
{
PyObject *module;
module = Py_InitModule3("mytime", pyInst_Methods,"Time module");
if (!module) return;
}
Build file
========
import os
from distutils.core import setup
from distutils.extension import Extension
if os.path.exists('C:\\Program Files (x86)'):
# 64 bit
ProgramFiles = 'Program Files (x86)'
else:
# 32 bit
ProgramFiles = 'Program Files'
setup(
name='Time Test',
author='Bob Cowdery',
ext_modules = [
Extension('mytime',
['pytime.cpp'],
include_dirs = ['C:\\' + ProgramFiles +
'\\Microsoft SDKs\\Windows\\v7.0A\\Include', 'C:\\Python26\\include'],
#define_macros = [("_AFXDLL", None)],
library_dirs = ['C:\\' + ProgramFiles +
'\\Microsoft SDKs\\Windows\\v7.0A\\Lib', 'C:\\Python26\\libs'],
libraries = ['User32', 'Gdi32', 'python26',
'odbc32', 'odbccp32']
)
]
)
On 06/05/2012 10:19, Bob Cowdery wrote:
On 06/05/2012 09:49, Cameron Simpson wrote:
On 06May2012 09:18, Bob Cowdery<b...@bobcowdery.plus.com> wrote:
| On 05/05/2012 23:05, Cameron Simpson wrote:
|> On 05May2012 20:33, Bob Cowdery<b...@bobcowdery.plus.com> wrote:
|> | [...] calls to time.time() always return the same
|> | time which is usually several seconds in the past or future
and always
|> | has no fractional part.
|>
|> Thought #1: you are calling time.time() and haven't unfortunately
|> renamed it? (I doubt this scenario, though the lack of
fractional part
|> is interesting.)
|
| Not sure what you mean by renamed it.
Like this:
from time import time
[...]
time = some_unfortunate_other_function
[...]
now = time() # calls wrong function
It seems unlikely, but possible.
| I also tried datetime and that had
| the same behaviour.
Makes my suggestion even less likely unless the time module itself gets
monkeypatched (i.e. "time.time = bad_function" somewhere).
I don't think the function is subverted unless there is some way inside
the vendor SDK or even DirectShow (the SDK uses this as a COM object)
which can somehow hijack it. It does catch up every few minutes so there
has to be a clue there.
|> | If I leave it long enough time will suddently
|> | jump forward after a few minutes, then again after a few
minutes more.
|> |
|> | I've never encountered this behaviour before and can't
understand what
|> | on earth is going on. If I call the 'C' time() function just
the other
|> | side of my call to the extension the time is ticking along
fine. It's
|> | just the one Python thread that is affected.
|> [...]
|>
|> Thought #2: On a UNIX system I'd be running the process under
strace (or
|> dtrace or ktrace depending on flavour) to see what actual OS
system calls are
|> being made during this behaviour. Is this feasible for you?
|
| I'm on Windows for this particular part of the application.
I'd guessed so. I've no Windows programming background; I was wondering
if there was something like this you had to hand on windows.
Maybe, but not that I know of.
| [...] But debugging into this is probably the only way. I
| looked at the built-in time module. As far as I can tell it just
calls
| the underlying C time() function as an extension. This is more
| mystifying as that is pretty much what I'm doing by checking the
time in
| my own extension module where it ticks along fine.
Hmm. A C extension I presume? How about writing a little pure Python
thread to call time.time(), and spin it off parallel to the rest of the
app; does it also get bad time.time() behaviour?
I've tried that. It's only the Python thread (or Python main thread)
that calls the extension that behaves like this. Other Python threads
tick along fine with the correct time including a fractional part.
| I have another
| scenario using a different part of their SDK where the time does
still
| tick but the fractional part is frozen, not 0 but frozen.
Curiouser and curiouser.
Indeed. Away now but battle will resume on Tuesday.
Bob
--
http://mail.python.org/mailman/listinfo/python-list
