More cache issues - Githubissues

tobixen commented 2 years ago

Are you sure this caching regime is a sane idea at all? :p I'd say you need test code going through the serialization-deserialization logic for all the different value types, and also with parameters included. And having a different code path on the seventh execution do lead into baffling bugs that are hard to reproduce.

Here is another weird traceback:

Error handling request
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/dist-packages/xandikos-0.2.8-py3.8.egg/xandikos/store/__init__.py", line 331, in _iter_with_filter_indexes
    file_values = self.index.get_values(name, etag, keys)
  File "/usr/local/lib/python3.8/dist-packages/xandikos-0.2.8-py3.8.egg/xandikos/store/index.py", line 56, in get_values
    raise KeyError(etag)
KeyError: '1e659304513a46e655ea527fa5bce366c4d4573c'
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/dist-packages/icalendar/prop.py", line 440, in from_ical
    raise ValueError(ical)
ValueError: b'20070715T040000Z'
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/dist-packages/aiohttp/web_protocol.py", line 422, in _handle_request
    resp = await self._request_handler(request)
  File "/usr/local/lib/python3.8/dist-packages/aiohttp/web_app.py", line 499, in _handle
    resp = await handler(request)
  File "/usr/local/lib/python3.8/dist-packages/xandikos-0.2.8-py3.8.egg/xandikos/web.py", line 1476, in xandikos_handler
    return await main_app.aiohttp_handler(request, options.route_prefix)
  File "/usr/local/lib/python3.8/dist-packages/xandikos-0.2.8-py3.8.egg/xandikos/webdav.py", line 2152, in aiohttp_handler
    response = await self._handle_request(request, environ)
  File "/usr/local/lib/python3.8/dist-packages/xandikos-0.2.8-py3.8.egg/xandikos/webdav.py", line 2108, in _handle_request
    return await do.handle(request, environ, self)
  File "/usr/local/lib/python3.8/dist-packages/xandikos-0.2.8-py3.8.egg/xandikos/webdav.py", line 1764, in handle
    return await reporter.report(
  File "/usr/local/lib/python3.8/dist-packages/xandikos-0.2.8-py3.8.egg/xandikos/webdav.py", line 353, in wrapper
    async for resp in req_fn(self, environ, *args, **kwargs):
  File "/usr/local/lib/python3.8/dist-packages/xandikos-0.2.8-py3.8.egg/xandikos/caldav.py", line 566, in report
    async for (href, resource) in webdav.traverse_resource(
  File "/usr/local/lib/python3.8/dist-packages/xandikos-0.2.8-py3.8.egg/xandikos/webdav.py", line 1205, in traverse_resource
    for (child_name, child_resource) in members_fn(resource):
  File "/usr/local/lib/python3.8/dist-packages/xandikos-0.2.8-py3.8.egg/xandikos/web.py", line 636, in calendar_query
    for (name, file, etag) in self.store.iter_with_filter(filter=filter):
  File "/usr/local/lib/python3.8/dist-packages/xandikos-0.2.8-py3.8.egg/xandikos/store/__init__.py", line 343, in _iter_with_filter_indexes
    if filter.check_from_indexes(name, file_values):
  File "/usr/local/lib/python3.8/dist-packages/xandikos-0.2.8-py3.8.egg/xandikos/icalendar.py", line 837, in check_from_indexes
    if not child_filter.match_indexes(indexes, self.tzify):
  File "/usr/local/lib/python3.8/dist-packages/xandikos-0.2.8-py3.8.egg/xandikos/icalendar.py", line 632, in match_indexes
    if not child.match_indexes(subindexes, tzify):
  File "/usr/local/lib/python3.8/dist-packages/xandikos-0.2.8-py3.8.egg/xandikos/icalendar.py", line 626, in match_indexes
    if self.time_range is not None and not self.time_range.match_indexes(
  File "/usr/local/lib/python3.8/dist-packages/xandikos-0.2.8-py3.8.egg/xandikos/icalendar.py", line 459, in match_indexes
    vs[name[2:]] = vDDDTypes(vDatetime.from_ical(value[0]))
  File "/usr/local/lib/python3.8/dist-packages/icalendar/prop.py", line 442, in from_ical
    raise ValueError('Wrong datetime format: %s' % ical)
ValueError: Wrong datetime format: b'20070715T040000Z'
 [18/Oct/2022:21:01:56 +0000] "REPORT /user/calendars/pythoncaldav-test/ HTTP/1.0" 500 231 "-" "Mozilla/5.0"

This one, as the previous one, fails on my standalone server but passes when running the same tests towards an "embedded" server. I suppose that the difference is that the "embedded" server is taken up and down for each test, while the "standalone" server is receiving the tests in a series. I'm pretty sure that I will be able to write up test code again with repeated report queries and the seventh to fail ... but I don't know when I will have the time.

Here is the report query:

<C:calendar-query xmlns:D="DAV:" xmlns:C="urn:ietf:params:xml:ns:caldav">
  <D:prop>
    <C:calendar-data/>
  </D:prop>
  <C:filter>
    <C:comp-filter name="VCALENDAR">
      <C:comp-filter name="VEVENT">
        <C:time-range start="20070713T170000Z" end="20070715T170000Z"/>
      </C:comp-filter>
    </C:comp-filter>
  </C:filter>
</C:calendar-query>

And the calendar contains one event:

BEGIN:VCALENDAR
VERSION:2.0
PRODID:-//Example Corp.//CalDAV Client//EN
BEGIN:VEVENT
SUMMARY:Bastille Day Party +1year
DTSTART:20070714T170000Z
DTEND:20070715T040000Z
DTSTAMP:20070712T182145Z
UID:20010712T182145Z-123401@example.com
END:VEVENT
END:VCALENDAR

tobixen commented 2 years ago

I managed to catch it through this test code. Test breaks with 3bdda2b424cc28afc0aeba5a934f7370073e63c5 but passes with a43ba24a13ac5a8810cc13b031fe73d6505e1e95.

    def testXandikosCacheDateSearch(self):
        # Create calendar, add event ...
        c = self._fixCalendar()
        e = c.save_event(ev1)

        # .. and search for it.
        r = c.search(comp_class=Event, start=datetime(2006, 7, 13, 17, 00, 00), end=datetime(2006, 7, 15, 17, 00, 00),  expand=False)
        assert e.instance.vevent.uid == r[0].instance.vevent.uid
        assert len(r) == 1

        r = c.search(comp_class=Event, start=datetime(2006, 7, 13, 17, 00, 00), end=datetime(2006, 7, 15, 17, 00, 00),  expand=False)
        r = c.search(comp_class=Event, start=datetime(2006, 7, 13, 17, 00, 00), end=datetime(2006, 7, 15, 17, 00, 00),  expand=False)
        r = c.search(comp_class=Event, start=datetime(2006, 7, 13, 17, 00, 00), end=datetime(2006, 7, 15, 17, 00, 00),  expand=False)
        r = c.search(comp_class=Event, start=datetime(2006, 7, 13, 17, 00, 00), end=datetime(2006, 7, 15, 17, 00, 00),  expand=False)
        r = c.search(comp_class=Event, start=datetime(2006, 7, 13, 17, 00, 00), end=datetime(2006, 7, 15, 17, 00, 00),  expand=False)
        r = c.search(comp_class=Event, start=datetime(2006, 7, 13, 17, 00, 00), end=datetime(2006, 7, 15, 17, 00, 00),  expand=False)
        r = c.search(comp_class=Event, start=datetime(2006, 7, 13, 17, 00, 00), end=datetime(2006, 7, 15, 17, 00, 00),  expand=False)
        r = c.search(comp_class=Event, start=datetime(2006, 7, 13, 17, 00, 00), end=datetime(2006, 7, 15, 17, 00, 00),  expand=False)
        assert e.instance.vevent.uid == r[0].instance.vevent.uid
        assert len(r) == 1

tobixen commented 2 years ago

For what it's worth, the test above also passes when using my fix 5f03c3c0fd8166ffc54a1ddf3ddc399a6c2067f8 :-)

tobixen commented 2 years ago

(Next time I'll try to write tests directly in the xandikos project instead of in my project ... it would probably be more useful)

jelmer commented 2 years ago

The attached PR should address this. You'll probably find more though, I haven't done an exhaustive check of all other property types.

jelmer / xandikos

More cache issues #219