msg158608 - (view) |
Author: Michael Foord (michael.foord) *  |
Date: 2012-04-18 12:26 |
time.time() can return None, or sometimes NaN. If it can't get a "proper" value from the OS then I would expect it to throw an exception. The docs don't mention anything about error conditions.
This was originally reported to Ubuntu One and there has been discussion / attempts to reproduce (it affects several people and so wasn't an isolated case):
https://bugs.launchpad.net/ubuntu/+source/ubuntuone-control-panel/+bug/844435
The issue is that with the unexpected response from time.time(), a ValueError was caused later when converting the time:
https://launchpadlibrarian.net/79283418/Traceback.txt
Traceback (most recent call last):
File "/usr/lib/python2.7/dist-packages/ubuntuone-control-panel/ubuntuone/controlpanel/web_client/libsoup.py", line 55, in _handler
msg.status_code, msg.get_uri().to_string(False))
File "/usr/lib/python2.7/logging/__init__.py", line 1120, in debug
self._log(DEBUG, msg, args, **kwargs)
File "/usr/lib/python2.7/logging/__init__.py", line 1249, in _log
record = self.makeRecord(self.name, level, fn, lno, msg, args, exc_info, func, extra)
File "/usr/lib/python2.7/logging/__init__.py", line 1223, in makeRecord
rv = LogRecord(name, level, fn, lno, msg, args, exc_info, func)
File "/usr/lib/python2.7/logging/__init__.py", line 280, in __init__
self.msecs = (ct - long(ct)) * 1000
ValueError: cannot convert float NaN to integer
|
msg158609 - (view) |
Author: Mark Dickinson (mark.dickinson) *  |
Date: 2012-04-18 12:31 |
Issue 14028 is related.
|
msg158611 - (view) |
Author: Martin v. Löwis (loewis) *  |
Date: 2012-04-18 12:48 |
What exact version of Python was used? What's the complete list of patches that was applied to this Python version?
As discussed in #14028, this behavior doesn't correspond to the code at all. So hardware error, compiler error, and downstream patches are likely sources of the problem.
|
msg158615 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2012-04-18 12:58 |
> time.time() can return None, or sometimes NaN
It is possible that it returns NaN, but it cannot return None. time.time() implementation of Python 2.7:
static PyObject *
time_time(PyObject *self, PyObject *unused)
{
double secs;
secs = floattime();
if (secs == 0.0) {
PyErr_SetFromErrno(PyExc_IOError);
return NULL;
}
return PyFloat_FromDouble(secs);
}
FYI I removed the (secs == 0.0) check in Python 3.3 (issue #14368, changeset 206c45f45236), it was a bug. time.time() *cannot* fail, it always return a float.
|
msg158616 - (view) |
Author: Michael Foord (michael.foord) *  |
Date: 2012-04-18 13:12 |
So NaN is a possible result from time.time()? Perhaps that should be mentioned in the docs. Is returning NaN preferable to failing with an exception?
|
msg158617 - (view) |
Author: Mark Dickinson (mark.dickinson) *  |
Date: 2012-04-18 13:14 |
> It is possible that it returns NaN
How is that possible? I can't see any way that the Python 2.7 implementation of floattime could return a NaN. In each case, floattime appears to be extracting integer fields from some suitable struct, and then combining them to produce a double; I can't see any scope for producing a NaN in any of the formulas used.
|
msg158775 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2012-04-19 23:34 |
> So NaN is a possible result from time.time()?
Oops. I don't know if it is possible. I just know that it cannot return None :-)
_PyTime_gettimeofday() fills a structure having two integer fields (tv_sec, tv_usec), and floattime() uses these fields to compute a double:
static PyObject*
floattime(void)
{
_PyTime_timeval t;
_PyTime_gettimeofday(&t);
return PyFloat_FromDouble((double)t.tv_sec + t.tv_usec * 1e-6);
}
I don't see how "(double)t.tv_sec + t.tv_usec * 1e-6" can generate NaN.
|
msg158904 - (view) |
Author: Éric Araujo (eric.araujo) *  |
Date: 2012-04-21 01:42 |
See http://patch-tracker.debian.org/package/python2.7 for the list of patches applied to Python 2.7 in Debian. I don’t know if there are more patches in Ubuntu.
|
msg235064 - (view) |
Author: (matham) |
Date: 2015-01-30 23:44 |
Hi guys,
I'm running into this issue on windows 7 using python 2.7.8 (x86) from the python website.
The following exception occurs while cython code calls a python function which emits a log. When replaying the same code it happens consistently:
Traceback (most recent call last):
File "g:\python\dev2\kivy\kivy\core\image\img_ffpyplayer.py", line 28, in _log_callback
logger_func[level]('ImageLoaderFFPy: {}'.format(message))
File "E:\Python27\lib\logging\__init__.py", line 1186, in error
self._log(ERROR, msg, args, **kwargs)
File "E:\Python27\lib\logging\__init__.py", line 1278, in _log
record = self.makeRecord(self.name, level, fn, lno, msg, args, exc_info, func, extra)
File "E:\Python27\lib\logging\__init__.py", line 1252, in makeRecord
rv = LogRecord(name, level, fn, lno, msg, args, exc_info, func)
File "E:\Python27\lib\logging\__init__.py", line 287, in __init__
self.msecs = (ct - long(ct)) * 1000
ValueError: cannot convert float NaN to integer
Even weirder, if I add a line like `print time.time()` right before `ct = time.time()` in logging\__init__.py no error occurs. But if I duplicate the print line twice, it crashes right there instead of raising an exception.
|
msg235065 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2015-01-30 23:47 |
I'm interested to investigate this issue, but right now I have no idea how to reproduce it. If I cannot reproduce the issue, I cannot investigate it.
Are you able to write a short Python script to reproduce the issue? Did you modify manually the system time? It looks like your application uses Kivy. Many Kivy does some maths which causes issues with the FPU and the error is reported later in time.time()? (I don't see how...)
|
msg235071 - (view) |
Author: (matham) |
Date: 2015-01-31 01:06 |
Ok, first, I was able to make it happen outside of kivy using only my code. However, I'm not sure it's of much help because it's using my ffmpeg based code (https://github.com/matham/ffpyplayer) which is not a simple script :)
The issue happens when ffmpeg emits logs through a c(cython) callback which calls the python logging code. But it only happened when I played a specific video. That's why i doubt I'd be able to make it happen in a sterile environment with a simple script. Also, I'm pretty sure that the log calling code is executed from ffmpeg's internal secondary threads (which I protect it with a mutex).
Anyway, I decided to upgrade my ffmpeg libraries to the most recent ffmpeg version and the problem went away. So was this maybe some bug in older ffmpeg which corrupted python? If you're interested in replicating it with the older ffmpeg, I can post some code using my ffpyplayer library.
|
msg400273 - (view) |
Author: Irit Katriel (iritkatriel) *  |
Date: 2021-08-25 15:21 |
The versions field includes 3.2 and 3.3, but from the discussion it seems the problem was only observed in 2.7, and went away after a third party upgrade.
It seems unlikely that we will be ably to make more progress on this issue. I propose we close it and investigate if a similar problem is reported on a current version.
|
msg400325 - (view) |
Author: Mark Dickinson (mark.dickinson) *  |
Date: 2021-08-26 08:46 |
> I propose we close it [...]
Seconded!
|
|
Date |
User |
Action |
Args |
2022-04-11 14:57:29 | admin | set | github: 58818 |
2021-08-26 08:46:55 | mark.dickinson | set | status: pending -> closed
messages:
+ msg400325 stage: test needed -> resolved |
2021-08-25 15:21:38 | iritkatriel | set | status: open -> pending
nosy:
+ iritkatriel messages:
+ msg400273
components:
+ Library (Lib) resolution: third party |
2015-01-31 01:06:23 | matham | set | messages:
+ msg235071 |
2015-01-30 23:47:55 | vstinner | set | messages:
+ msg235065 |
2015-01-30 23:44:06 | matham | set | nosy:
+ matham messages:
+ msg235064
|
2012-04-21 01:42:30 | eric.araujo | set | nosy:
+ eric.araujo messages:
+ msg158904
|
2012-04-19 23:34:09 | vstinner | set | messages:
+ msg158775 |
2012-04-19 21:27:41 | vstinner | set | title: time.time can return None or NaN -> time.time can return NaN |
2012-04-18 13:14:25 | mark.dickinson | set | messages:
+ msg158617 |
2012-04-18 13:12:27 | michael.foord | set | messages:
+ msg158616 |
2012-04-18 12:58:07 | vstinner | set | messages:
+ msg158615 |
2012-04-18 12:48:50 | loewis | set | nosy:
+ loewis messages:
+ msg158611
|
2012-04-18 12:32:00 | rye | set | nosy:
+ rye
|
2012-04-18 12:31:20 | mark.dickinson | set | nosy:
+ mark.dickinson messages:
+ msg158609
|
2012-04-18 12:30:32 | michael.foord | set | versions:
+ Python 2.7, Python 3.2, Python 3.3 |
2012-04-18 12:28:21 | michael.foord | set | type: behavior stage: test needed |
2012-04-18 12:26:27 | michael.foord | create | |