getFolderContents: serious performance problem

Hi,

CPSDefault.utils.getFolderContents causes a big performance problem on a site
we installed. A subsection containing about 4000 documents takes some 40
secondes to display for a 'SectionReader' user, versus 7 seconds for the Manager.

The profiler points out one main culprit: getRolesInContext (and also
DateTime's _parse_args). (*)

My first try was to give the View permission to the Authenticated role in the
subsection instead of using a SectionReader local role, but there wasn't much
improvement. After reading CPSDefault.utils.filterContents, the reason is obvious:
{{{
         # filter non effective or expired published content
         if not _checkPermission(ModifyPortalContent, item):
             review_state = wtool.getInfoFor(item, 'review_state', 'nostate')
             if review_state == 'published':
                 doc = item.getContent()
                 if now < doc.effective() or now > doc.expires():
                     continue
}}}

(_checkPermission could be pushed down in the tests; but I'm not sure whether
that would be much more efficient. The dates tests may also be costly.)

After my colleague remarked that searches were much quicker (~ 5 seconds, and
with a more complex display), we tried to force using
getCatalogFolderContents, and lo! folder_view became 8 times faster.

So I'd like to know

* How to systematically use getCatalogFolderContents instead of
getFolderContents (in a clean way :) ) -- I'm not yet comfortable with CPS
views' many levels of inclusion

* Why it's not the case already (I've had incomplete indexes, but assume it's
my fault)

* Bonus question: can one sort on several indexes -- i.e. some of my documents
have a specific field which should be used as a default sort key; how to get
also documents of other types?


Regards,

yves


(* Some profiler results, for 10 folder_view with 3657 documents:

Statistics:

    ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     78112   11.510    0.000   24.450    0.000 /usr/local/Zope-2.9.5/instance/gps/Products/CPSUserFolder/CPSUserFolder.py:963(getRolesInContext)
2127866/2117662   11.400    0.000   13.850    0.000 :0(getattr)
    138109    9.670    0.000   20.230    0.000 /usr/local/Zope-2.9.4/lib/python/DateTime/DateTime.py:516(_parse_args)
184080/143144    9.010    0.000   51.040    0.000 :0(load)
    138109    3.620    0.000   23.850    0.000 /usr/local/Zope-2.9.4/lib/python/DateTime/DateTime.py:505(__init__)
    849308    3.360    0.000    3.820    0.000 :0(hasattr)
        10    3.210    0.321  118.100   11.810 /usr/local/Zope-2.9.5/instance/gps/Products/CPSDefault/utils.py:198(filterContents)
    159132    3.070    0.000    3.080    0.000 :0(aq_get)
    997145    2.610    0.000    2.610    0.000 :0(get)
    112513    2.340    0.000   16.420    0.000 /usr/local/Zope-2.9.4/lib/python/ZODB/FileStorage/FileStorage.py:544(load)
     71567    2.160    0.000   68.340    0.001 /usr/local/Zope-2.9.4/lib/python/ZODB/Connection.py:740(_setstate)
     73441    2.070    0.000   29.410    0.000 /usr/local/Zope-2.9.4/lib/python/AccessControl/ImplPython.py:466(checkPermission)
    553090    2.040    0.000    2.040    0.000 :0(floor)
    759731    2.000    0.000    2.000    0.000 :0(isinstance)

[Urgh. Two mixed Zope instances? No wonder I've had troubles putting breakpoints.]

Per callees:

utils.py:198(filterContents)   :0(append)(36570)    1.020
                                :0(getattr)(36570)   13.850
                                :0(startswith)(36570)    0.310
                                Connection.py:720(setstate)(45385)   68.990
                                DateTime.py:505(__init__)(10)   23.850
                                DateTime.py:1245(greaterThan)(36570)    0.080
                                DateTime.py:1321(lessThan)(36570)    0.110
                                DublinCore.py:287(effective)(36570)    0.520
                                DublinCore.py:299(expires)(36570)    1.060
                                ObjectManager.py:383(objectIds)(10)    0.020
                                ProxyBase.py:194(getContent)(36570)    9.330
                                SimpleItem.py:81(getId)(36570)    0.650
                                WorkflowTool.py:304(getInfoFor)(36570)   25.360
                                timer.py:66(__init__)(10)    0.000
                                timer.py:75(mark)(20)    0.000
                                utils.py:66(getToolByName)(20)    3.170
                                utils.py:121(_checkPermission)(73140)   31.110

Connection.setstate's time is spurious, the other ones look credible)

_______________________________________________
cps-devel mailing list
http://lists.nuxeo.com/mailman/listinfo/cps-devel