progress updates occasionally behave strangely

[erdmann]

When I run pytest in the root pyvips folder, more often than not I'm getting this at the very end:

===================================================================== warnings summary ======================================================================
tests/test_progress.py::TestProgress::test_progress_fields
  /opt/anaconda3/lib/python3.8/site-packages/_pytest/unraisableexception.py:78: PytestUnraisableExceptionWarning: Exception ignored from cffi callback <function _marshal_image_progress at 0x7fad0111eca0>: None

  Traceback (most recent call last):
    File "/home/erdmann/src/pyvips/pyvips/gobject.py", line 22, in _marshal_image_progress
      callback(image, progress)
    File "/home/erdmann/src/pyvips/tests/test_progress.py", line 45, in posteval_cb
      assert progress.percent == 100
  AssertionError: assert 99 == 100
   +  where 99 = <cdata 'struct _VipsProgress *' 0x5600cf0cf4d0>.percent

    warnings.warn(pytest.PytestUnraisableExceptionWarning(msg))

-- Docs: https://docs.pytest.org/en/stable/warnings.html

It doesn't consistently happen, though. I have also noticed that when I hook up tqdm to a progress callback in pyvips it also seems to sometimes fail to fully reach the last tick. Is this a bug, possibly caused by a roundoff error somewhere?

[jcupitt]

Huh strange, it seems reliable for me. I tried:

for i in {1..100}; do echo loop $i ...; pytest > /dev/null || break; done

And it gets to the end without issue. Perhaps there's some kind of race condition :(

[erdmann]

Your loop also reaches the end for me too. I think that at least in my case that's because the issue shows up as a warning rather than a full test failure. In case it's helpful, here's the full output of the case in which running pytest raises a warning:

$ pytest
================================================================== test session starts ==================================================================
platform linux -- Python 3.8.6, pytest-6.2.1, py-1.11.0, pluggy-0.13.1
rootdir: /home/erdmann/src/pyvips, configfile: tox.ini
plugins: doctestplus-0.5.0, astropy-header-0.1.1, openfiles-0.4.0, anyio-3.1.0, remotedata-0.3.2, arraydiff-0.3
collected 50 items                                                                                                                                      

tests/test_connections.py ......                                                                                                                  [ 12%]
tests/test_constants.py ............                                                                                                              [ 36%]
tests/test_gvalue.py ............                                                                                                                 [ 60%]
tests/test_image.py ...........                                                                                                                   [ 82%]
tests/test_progress.py ...                                                                                                                        [ 88%]
tests/test_saveload.py ......                                                                                                                     [100%]

=================================================================== warnings summary ====================================================================
tests/test_progress.py::TestProgress::test_progress_fields
  /opt/anaconda3/lib/python3.8/site-packages/_pytest/unraisableexception.py:78: PytestUnraisableExceptionWarning: Exception ignored from cffi callback <function _marshal_image_progress at 0x7f2c446afe50>: None

  Traceback (most recent call last):
    File "/home/erdmann/src/pyvips/pyvips/gobject.py", line 22, in _marshal_image_progress
      callback(image, progress)
    File "/home/erdmann/src/pyvips/tests/test_progress.py", line 45, in posteval_cb
      assert progress.percent == 100
  AssertionError: assert 99 == 100
   +  where 99 = <cdata 'struct _VipsProgress *' 0x559254b78770>.percent

    warnings.warn(pytest.PytestUnraisableExceptionWarning(msg))

-- Docs: https://docs.pytest.org/en/stable/warnings.html
============================================================= 50 passed, 1 warning in 3.17s =============================================================

[jcupitt]

Huh that's a bit surprising, I hadn't expected a test failure to be just a warning.

I tried again without the > /dev/null and it ran cleanly. Maybe it's the libvips version? I'm using git master libvips.

[jcupitt]

I checked the logs and 8.13 has some changes to hide setup loops from progress reporting. Could that be it?

[kleisauke]

libvips 8.13 was released, see: https://github.com/libvips/libvips/releases/tag/v8.13.0. Would you be able to test again?

[kleisauke]

Looking at this further, I think commit https://github.com/libvips/libvips/commit/111eef0049068bd12e0ab5ffa1e26246f90a0a5f fixes this.