alexmojaki / littleutils

Small personal collection of python utility functions, partly just for fun.
MIT License
4 stars 6 forks source link

0.2.4: testing fails #10

Open mtelka opened 3 months ago

mtelka commented 3 months ago

I'm running littleutils tests and I found that testing failed:

py39: commands[0]> python littleutils/__init__.py
**********************************************************************
File "/tmp/littleutils-0.2.4/littleutils/__init__.py", line 277, in __main__.timer
Failed example:
    with timer(description='Doing', log=PrintingLogger()):
       sleep(0.3)               # doctest:+ELLIPSIS
Expected:
    Doing took 0.3... seconds
Got:
    Doing took 0.29993605613708496 seconds
**********************************************************************
1 items had failures:
   1 of   3 in __main__.timer
***Test Failed*** 1 failures.
py39: exit 1 (0.89 seconds) /tmp/littleutils-0.2.4> python littleutils/__init__.py pid=24445
  py39: FAIL code 1 (0.94=setup[0.06]+cmd[0.89] seconds)
  evaluation failed :( (1.92 seconds)

This is regression from version 0.2.2 where testing passed.

mtelka commented 3 months ago

The issue seems to be not directly related to littleutils. The testing for 0.2.2 passed when I previously tried it (Feb 2023) but now it fails the same way as for 0.2.4. So apparently the problem is in something else in the environment.

alexmojaki commented 3 months ago
@contextmanager
def timer(description='Operation', log=None):
    """
    Simple context manager which logs (if log is provided)
    or prints the time taken in seconds for the block to complete.

    >>> with timer():
    ...    sleep(0.1)               # doctest:+ELLIPSIS
    Operation took 0.1... seconds

    >>> with timer('Sleeping'):
    ...    sleep(0.2)               # doctest:+ELLIPSIS
    Sleeping took 0.2... seconds

    >>> with timer(description='Doing', log=PrintingLogger()):
    ...    sleep(0.3)               # doctest:+ELLIPSIS
    Doing took 0.3... seconds

    """

    start = time()
    yield
    elapsed = time() - start
    message = '%s took %s seconds' % (description, elapsed)
    (print if log is None else log.info)(message)

If time.time says that time.sleep(0.3) took less than 0.3 seconds, sounds like a problem with time.time or time.sleep.

mtelka commented 3 months ago

Maybe the problem is related to floating point changes in GCC 13. See https://unicode-org.atlassian.net/browse/ICU-22629 for more details. Python (version 3.9.19) is compiled using GCC 13 here without the -fexcess-precision=fast flag.

BTW, the test failure is always reproducible.

mtelka commented 3 months ago

The excess precision is probably not related because Python use C++ rarely. I identified these C++ sources in Python 3.9.19 tree only:

Python-3.9.19/Tools/msi/bundle/bootstrap/pch.cpp
Python-3.9.19/Tools/msi/bundle/bootstrap/pythonba.cpp
Python-3.9.19/Tools/msi/bundle/bootstrap/PythonBootstrapperApplication.cpp
Python-3.9.19/PC/pyshellext.cpp
Python-3.9.19/PC/python_uwp.cpp

and all of them seems to be Windows specific.