Performance issue with utils.get_plugin_names()

[zopyx]

As part of debugging session of Plone 5 I came across the problem that one request triggers two calls to yafowil.utils.get_plugin_names() per request with an execution time of about 0.5 to 0.7 per seconds.

1) The calls are not cached (not sure if the result should cachable)

2) yafowil.plone seems to be used inside a test fixture

unimr.ldaplogin/src/unimr/ldaplogin/testing.py:import yafowil.plone
unimr.ldaplogin/src/unimr/ldaplogin/testing.py:        self.loadZCML(package=yafowil.plone)
Binary file unimr.ldaplogin/src/unimr/ldaplogin/testing.pyc matches
unimr.policy/src/unimr/policy/testing.py:import yafowil.plone
unimr.policy/src/unimr/policy/testing.py:        self.loadZCML(package=yafowil.plone)
Binary file unimr.policy/src/unimr/policy/testing.pyc matches

Not sure why get_plugin_names() is called inside our production setup.

-> result = list(set([_.dist.project_name for _ in get_entry_points(ns=ns)]))
(Pdb) where
  /media/ajung/data/sandboxes/plone5-buildout/eggs/Zope2-2.13.26-py2.7.egg/ZServer/PubCore/ZServerPublisher.py(31)__init__()
-> response=b)
  /media/ajung/data/sandboxes/plone5-buildout/eggs/Products.ZopeProfiler-2.0.2-py2.7.egg/Products/ZopeProfiler/MonkeyPatcher.py(35)__call__()
-> return self._function(*args,**kw)
  /media/ajung/data/sandboxes/plone5-buildout/eggs/Products.ZopeProfiler-2.0.2-py2.7.egg/Products/ZopeProfiler/ZopeProfiler.py(411)_profilePublishModule()
-> request=request, response=response)
  /media/ajung/data/sandboxes/plone5-buildout/eggs/Zope2-2.13.26-py2.7.egg/ZPublisher/Publish.py(455)publish_module()
-> environ, debug, request, response)
  /media/ajung/data/sandboxes/plone5-buildout/eggs/Zope2-2.13.26-py2.7.egg/ZPublisher/Publish.py(249)publish_module_standard()
-> response = publish(request, module_name, after_list, debug=debug)
  /media/ajung/data/sandboxes/plone5-buildout/eggs/Zope2-2.13.26-py2.7.egg/ZPublisher/Publish.py(138)publish()
-> request, bind=1)
  /media/ajung/data/sandboxes/plone5-buildout/eggs/Zope2-2.13.26-py2.7.egg/ZPublisher/mapply.py(77)mapply()
-> if debug is not None: return debug(object,args,context)
  /media/ajung/data/sandboxes/plone5-buildout/eggs/Zope2-2.13.26-py2.7.egg/ZPublisher/Publish.py(48)call_object()
-> result=apply(object,args) # Type s<cr> to step into published object.
  /media/ajung/data/sandboxes/plone5-buildout/eggs/yafowil.plone-2.4.1-py2.7.egg/yafowil/plone/resources.py(69)__call__()
-> enabled_resources(self._resource_type)
  /media/ajung/data/sandboxes/plone5-buildout/eggs/yafowil.plone-2.4.1-py2.7.egg/yafowil/plone/resources.py(23)enabled_resources()
-> for plugin_name in get_plugin_names():
> /media/ajung/data/sandboxes/plone5-buildout/eggs/yafowil-2.2.4-py2.7.egg/yafowil/utils.py(41)get_plugin_names()
-> result = list(set([_.dist.project_name for _ in get_entry_points(ns=ns)]))

[rnixx]

Hi,

get_plugin_names() is used to aggregate JS and CSS resources to deliver and to initialize the factory with addon blueprints.

The return value is unique, thus can safely be cached.

[zopyx]

We have indication that the related resources are never cached and reloaded with every request independent of its URL..this slows down sites. Some caching at some level is needed.

[rnixx]

Some caching at some level is needed.

True. As first step i added caching for get_plugin_names here https://github.com/bluedynamics/yafowil/commit/0fd7c1a4054009359bf4033dc4a7c8beee7ba135. May you be so kind and check whether this improves the situation?

The second improvement must be caching of https://github.com/bluedynamics/yafowil.plone/blob/master/src/yafowil/plone/resources.py#L66. I'll have a look at it within the next days, need to finish some other stuff first.

[krissik]

I have tested this. It seems to improve loading of yafowil.plone.js if I load it directly , e.g. http://localhost:8082/uni3/yafowil.plone.js?version=None

But I can not see any improvement during start page load:

[rnixx]

fixed via https://github.com/bluedynamics/yafowil.plone/pull/20