khal: Test failures in 0.9.2

Building khal 0.9.2 in GNU Guix, the following tests fail.

Actually, the latter three tests are also failing for 0.9.1. test_db_needs_update is the only new failure.

Do you think these represent a real problem, or can we skip these tests?

============================= test session starts ==============================
platform linux -- Python 3.5.2 -- py-1.4.31 -- pytest-2.7.3
rootdir: /tmp/guix-build-khal-0.9.2.drv-0/khal-0.9.2, inifile: 
plugins: cov
collected 246 items

tests/backend_test.py ..........................
tests/cal_display_test.py ....x.
tests/cli_test.py ..............................
tests/configwizard_test.py .
tests/controller_test.py ..........
tests/event_test.py ..........................................
tests/khalendar_test.py ...F...............FF
tests/khalendar_utils_test.py ......................................
tests/settings_test.py .........
tests/terminal_test.py ...
tests/utils_test.py .................................................
tests/vdir_test.py x.F
tests/vtimezone_test.py ...
tests/ui/test_calendarwidget.py ...
tests/ui/test_startendeditor.py .
tests/ui/test_widgets.py .

=================================== FAILURES ===================================
______________________ TestCalendar.test_db_needs_update _______________________

self = <tests.khalendar_test.TestCalendar object at 0x7ffff00660b8>
coll_vdirs = (<khal.khalendar.khalendar.CalendarCollection object at 0x7ffff0066f60>, {'a_calendar': <khal.khalendar.vdir.Vdir obje...te': <khal.khalendar.vdir.Vdir object at 0x7ffff0066cf8>, 'work': <khal.khalendar.vdir.Vdir object at 0x7ffff0066c50>})

    def test_db_needs_update(self, coll_vdirs):
        coll, vdirs = coll_vdirs
    
        print('init')
        for calendar in coll._calendars:
            print('{}: saved ctag: {}, vdir ctag: {}'.format(
                calendar, coll._local_ctag(calendar), coll._backend.get_ctag(calendar)))
        assert len(list(vdirs[cal1].list())) == 0
        assert coll._needs_update(cal1) is False
        sleep(0.01)
    
        vdirs[cal1].upload(item_today)
        print('upload')
        for calendar in coll._calendars:
            print('{}: saved ctag: {}, vdir ctag: {}'.format(
                calendar, coll._local_ctag(calendar), coll._backend.get_ctag(calendar)))
        assert len(list(vdirs[cal1].list())) == 1
>       assert coll._needs_update(cal1) is True
E       assert <bound method CalendarCollection._needs_update of <khal.khalendar.khalendar.CalendarCollection object at 0x7ffff0066f60>>('foobar') is True
E        +  where <bound method CalendarCollection._needs_update of <khal.khalendar.khalendar.CalendarCollection object at 0x7ffff0066f60>> = <khal.khalendar.khalendar.CalendarCollection object at 0x7ffff0066f60>._needs_update

tests/khalendar_test.py:85: AssertionError
----------------------------- Captured stdout call -----------------------------
init
a_calendar: saved ctag: 1487011021000000000.000000000, vdir ctag: 1487011021000000000.000000000
private: saved ctag: 1487011021000000000.000000000, vdir ctag: 1487011021000000000.000000000
work: saved ctag: 1487011021000000000.000000000, vdir ctag: 1487011021000000000.000000000
foobar: saved ctag: 1487011021000000000.000000000, vdir ctag: 1487011021000000000.000000000
upload
a_calendar: saved ctag: 1487011021000000000.000000000, vdir ctag: 1487011021000000000.000000000
private: saved ctag: 1487011021000000000.000000000, vdir ctag: 1487011021000000000.000000000
work: saved ctag: 1487011021000000000.000000000, vdir ctag: 1487011021000000000.000000000
foobar: saved ctag: 1487011021000000000.000000000, vdir ctag: 1487011021000000000.000000000
____________________________ test_default_calendar _____________________________

coll_vdirs = (<khal.khalendar.khalendar.CalendarCollection object at 0x7fffef41d240>, {'a_calendar': <khal.khalendar.vdir.Vdir obje...te': <khal.khalendar.vdir.Vdir object at 0x7fffef41d080>, 'work': <khal.khalendar.vdir.Vdir object at 0x7fffef41dcf8>})

    def test_default_calendar(coll_vdirs):
        """test if an update to the vdir is detected by the CalendarCollection"""
        coll, vdirs = coll_vdirs
        vdir = vdirs['foobar']
        event = coll.new_event(event_today, 'foobar')
    
        assert len(list(coll.get_events_on(today))) == 0
    
        vdir.upload(event)
        sleep(0.01)
        href, etag = list(vdir.list())[0]
        assert len(list(coll.get_events_on(today))) == 0
    
        coll.update_db()
        sleep(0.01)
>       assert len(list(coll.get_events_on(today))) == 1
E       assert 0 == 1
E        +  where 0 = len([])
E        +    where [] = list(<itertools.chain object at 0x7ffff1521208>)
E        +      where <itertools.chain object at 0x7ffff1521208> = <bound method CalendarCollection.get_events_on of <khal.khalendar.khalendar.CalendarCollection object at 0x7fffef41d240>>(datetime.date(2017, 2, 13))
E        +        where <bound method CalendarCollection.get_events_on of <khal.khalendar.khalendar.CalendarCollection object at 0x7fffef41d240>> = <khal.khalendar.khalendar.CalendarCollection object at 0x7fffef41d240>.get_events_on

tests/khalendar_test.py:342: AssertionError
__________________________ test_only_update_old_event __________________________

coll_vdirs = (<khal.khalendar.khalendar.CalendarCollection object at 0x7ffff380b748>, {'a_calendar': <khal.khalendar.vdir.Vdir obje...te': <khal.khalendar.vdir.Vdir object at 0x7ffff0077cf8>, 'work': <khal.khalendar.vdir.Vdir object at 0x7ffff1521ac8>})
monkeypatch = <_pytest.monkeypatch.monkeypatch object at 0x7ffff0077d30>

    def test_only_update_old_event(coll_vdirs, monkeypatch):
        coll, vdirs = coll_vdirs
    
        href_one, etag_one = vdirs[cal1].upload(coll.new_event(dedent("""
        BEGIN:VEVENT
        UID:meeting-one
        DTSTART;VALUE=DATE:20140909
        DTEND;VALUE=DATE:20140910
        SUMMARY:first meeting
        END:VEVENT
        """), cal1))
    
        href_two, etag_two = vdirs[cal1].upload(coll.new_event(dedent("""
        BEGIN:VEVENT
        UID:meeting-two
        DTSTART;VALUE=DATE:20140910
        DTEND;VALUE=DATE:20140911
        SUMMARY:second meeting
        END:VEVENT
        """), cal1))
    
        sleep(0.01)
        coll.update_db()
        sleep(0.01)
        assert not coll._needs_update(cal1)
    
        old_update_vevent = coll._update_vevent
        updated_hrefs = []
    
        def _update_vevent(href, calendar):
            updated_hrefs.append(href)
            return old_update_vevent(href, calendar)
        monkeypatch.setattr(coll, '_update_vevent', _update_vevent)
    
        href_three, etag_three = vdirs[cal1].upload(coll.new_event(dedent("""
        BEGIN:VEVENT
        UID:meeting-three
        DTSTART;VALUE=DATE:20140911
        DTEND;VALUE=DATE:20140912
        SUMMARY:third meeting
        END:VEVENT
        """), cal1))
        sleep(0.01)
    
        assert coll._needs_update(cal1)
        coll.update_db()
        sleep(0.01)
>       assert updated_hrefs == [href_three]
E       assert ['meeting-thr...ting-one.ics'] == ['meeting-three.ics']
E         Left contains more items, first extra item: 'meeting-two.ics'
E         Use -v to get the full diff

tests/khalendar_test.py:400: AssertionError
_______________________________ test_etag_sleep ________________________________

tmpdir = local('/tmp/guix-build-khal-0.9.2.drv-0/pytest-nixbld/pytest-0/test_etag_sleep0')

    def test_etag_sleep(tmpdir):
        fpath = os.path.join(str(tmpdir), 'foo')
    
        file_ = open(fpath, 'w')
        file_.write('foo')
        file_.close()
    
        old_etag = vdir.get_etag_from_file(fpath)
        time.sleep(0.1)
    
        file_ = open(fpath, 'w')
        file_.write('foo')
        file_.close()
    
        new_etag = vdir.get_etag_from_file(fpath)
    
>       assert old_etag != new_etag
E       assert '1487011057000000000.000000000' != '1487011057000000000.000000000'

tests/vdir_test.py:88: AssertionError
============== 4 failed, 240 passed, 2 xfailed in 102.86 seconds ===============

About this issue

  • Original URL
  • State: closed
  • Created 7 years ago
  • Comments: 24 (24 by maintainers)

Most upvoted comments

And this is the output of the script on ext4:

mtime_ns: 1487093769000000000
mtime: 1487093769.0
1487093769.051025
---
mtime_ns: 1487093769000000000
mtime: 1487093769.0
1487093769.151572
---
mtime_ns: 1487093770000000000
mtime: 1487093770.0
1487093770.153201
---

rough outline of what’s probably (going) on here:

  • we are using the time a file was last modified (mtime) to check if we need to update it
  • we observe, that sometimes, even though we did write to the file, the mtime doesn’t change
  • we/I first hypothesized that we just wrote to quickly to it, so that the mtime really does not change (below resolution of mtime), we therefore introduced the calls to sleep()
  • even with very long sleeps, this did not always make the failures go away
  • next hypothesis was, that the write was still in the OS’s cache, we therefore introduced fsync() (see khal/khalendar/vdir.py) to make sure the changes get written to disk
  • we also made sure to fsync() the actual vdir, because someone believed that metadata is associated with the directory a file is in
  • turns out, the problems didn’t go away after all – I really need to take a closer look at this again

Quoting Hugo Osvaldo Barrera (2017-02-14 14:08:42)

@lfam Can you provide the exact version of all dependencies (pip freeze).

My python 3.5 is 3.5.3, but I don’t expect that patch different to be of importance, TBH.

@geier I might be out of the loop here, but, why sleep instead of freezegun? (sorry if this has been discussed before and I skipped it).

– You are receiving this because you were mentioned. Reply to this email directly or view it on GitHub: https://github.com/pimutils/khal/issues/574#issuecomment-279702631