Another indexing problem ... "index based filter not matching real file filter"

[tobixen]

I've turned on paranoid and index-threshold=0 in the caldav functional tests now ... this stops me from doing a release, so I will have to revert it unless we get this issue resolved relatively fast :-)

I get this traceback:

E           caldav.lib.error.ReportError: ReportError at '500 Internal Server Error
E
E           b'500 Internal Server Error\n\nServer got itself in trouble'', reason no reason

caldav/objects.py:194: ReportError
---------------------------------------------------------- Captured log call -----------------------------------------------------------
ERROR    aiohttp.server:web_protocol.py:403 Error handling request
Traceback (most recent call last):
  File "/usr/lib/python3.10/site-packages/aiohttp/web_protocol.py", line 433, in _handle_request
    resp = await request_handler(request)
  File "/usr/lib/python3.10/site-packages/aiohttp/web_app.py", line 504, in _handle
    resp = await handler(request)
  File "/home/tobias/caldav/tests/test_caldav.py", line 2199, in xandikos_handler
    return await mainapp.aiohttp_handler(request, "/")
  File "/usr/lib/python3.10/site-packages/xandikos-0.2.8-py3.10.egg/xandikos/webdav.py", line 2152, in aiohttp_handler
    response = await self._handle_request(request, environ)
  File "/usr/lib/python3.10/site-packages/xandikos-0.2.8-py3.10.egg/xandikos/webdav.py", line 2108, in _handle_request
    return await do.handle(request, environ, self)
  File "/usr/lib/python3.10/site-packages/xandikos-0.2.8-py3.10.egg/xandikos/webdav.py", line 1764, in handle
    return await reporter.report(
  File "/usr/lib/python3.10/site-packages/xandikos-0.2.8-py3.10.egg/xandikos/webdav.py", line 353, in wrapper
    async for resp in req_fn(self, environ, *args, **kwargs):
  File "/usr/lib/python3.10/site-packages/xandikos-0.2.8-py3.10.egg/xandikos/caldav.py", line 566, in report
    async for (href, resource) in webdav.traverse_resource(
  File "/usr/lib/python3.10/site-packages/xandikos-0.2.8-py3.10.egg/xandikos/webdav.py", line 1205, in traverse_resource
    for (child_name, child_resource) in members_fn(resource):
  File "/usr/lib/python3.10/site-packages/xandikos-0.2.8-py3.10.egg/xandikos/web.py", line 637, in calendar_query
    for (name, file, etag) in self.store.iter_with_filter(filter=filter):
  File "/usr/lib/python3.10/site-packages/xandikos-0.2.8-py3.10.egg/xandikos/store/__init__.py", line 351, in _iter_with_filter_indexes
    raise AssertionError(
AssertionError: index based filter not matching real file filter

All tests pass if I turn off paranoid or if I turn the index threshold high.

I realize that this is a bit too little information for further debugging, but ... I need to sleep now, will get back with more details tomorrow.

[tobixen]

(master version of xandikos, fwiw)

[jelmer]

Propose #236 to add some more debug data; can you post the results with that?

[tobixen]

AssertionError: index based filter CalendarFilter([ComponentFilter('VCALENDAR', 
 children=[ComponentFilter('VTODO', 
  children=[PropertyFilter('COMPLETED', 
   children=[], is_not_defined=True, time_range=None), 
   PropertyFilter('STATUS', 
     children=[TextMatcher('STATUS', 'COMPLETED', 
         collation=<function <lambda> at 0x7fcad093f9a0>, negate_condition=True)], 
     is_not_defined=False, time_range=None), 
   PropertyFilter('STATUS', 
     children=[TextMatcher('STATUS', 'CANCELLED', 
       collation=<function <lambda> at 0x7fcad093f9a0>, 
     negate_condition=True)], 
     is_not_defined=False, time_range=None)], 
   is_not_defined=False, time_range=None)], 
 is_not_defined=False, time_range=None)]) 
(values: {'C=VCALENDAR/C=VTODO/P=COMPLETED': [b'20221118T065947Z'], 'C=VCALENDAR/C=VTODO/P=STATUS': [b'NEEDS-ACTION', b'COMPLETED', b'NEEDS-ACTION']}) not matching real file filter
=================================================

[tobixen]

Here is the body of my 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="VTODO">
        <C:prop-filter name="COMPLETED">
          <C:is-not-defined/>
        </C:prop-filter>
        <C:prop-filter name="STATUS">
          <C:text-match collation="i;octet" negate-condition="yes">COMPLETED</C:text-match>
        </C:prop-filter>
        <C:prop-filter name="STATUS">
          <C:text-match collation="i;octet" negate-condition="yes">CANCELLED</C:text-match>
        </C:prop-filter>
      </C:comp-filter>
    </C:comp-filter>
  </C:filter>
</C:calendar-query>

[tobixen]

The calendar has two components - the first one is a bit exotic, but I believe it's valid (or perhaps not - the RECURRENCE-ID for the last subcomponent seems to be wrong). It has STATUS:NEEDS-ACTION, but then it also defines recurrences with STATUS:COMPLETED. The component has been updated ... first the task was put in without recurrences, a search done, and then the recurrences with STATUS:COMPLETED has been added. Perhaps that's why there is something wrong with the index?

BEGIN:VCALENDAR
VERSION:2.0
PRODID:-//Example Corp.//CalDAV Client//EN
BEGIN:VTODO
CATEGORIES:FAMILY,FINANCE
CLASS:CONFIDENTIAL
DTSTAMP:19920901T130000Z
DTSTART:19920415T133000Z
DUE:19920516T045959Z
PRIORITY:1
RRULE:FREQ=YEARLY
STATUS:NEEDS-ACTION
SUMMARY:Yearly Income Tax Preparation
UID:[email protected]
END:VTODO
BEGIN:VTODO
CATEGORIES:FAMILY,FINANCE
CLASS:CONFIDENTIAL
COMPLETED:20221118T071514Z
DTSTAMP:19920901T130000Z
DTSTART:19920415T133000Z
DUE:19920516T045959Z
PRIORITY:1
RECURRENCE-ID:19920415T133000Z
SEQUENCE:1
STATUS:COMPLETED
SUMMARY:Yearly Income Tax Preparation
UID:[email protected]
END:VTODO
BEGIN:VTODO
CATEGORIES:FAMILY,FINANCE
CLASS:CONFIDENTIAL
DTSTAMP:19920901T130000Z
DTSTART:20231118T071514Z
DUE:20231218T224513Z
PRIORITY:1
RECURRENCE-ID;RANGE=THISANDFUTURE:20231018T174515
SEQUENCE:2
STATUS:NEEDS-ACTION
SUMMARY:Yearly Income Tax Preparation
UID:[email protected]
END:VTODO
END:VCALENDAR

BEGIN:VCALENDAR
VERSION:2.0
PRODID:-//Example Corp.//CalDAV Client//EN
BEGIN:VTODO
CATEGORIES:CHORE
DTSTAMP:20221013T151313Z
DTSTART:20221017T065500Z
DURATION:PT10M
PRIORITY:3
RRULE:FREQ=WEEKLY;COUNT=3;BYMINUTE=55;BYHOUR=6;BYDAY=MO
SUMMARY:Take out the thrash before the collectors come.
UID:takeoutthethrash
END:VTODO
END:VCALENDAR

[tobixen]

Oh right, recurrences are not supported yet ...