Logging on list operations slows down operation by about 500%
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
neutron |
Fix Released
|
High
|
Salvatore Orlando | ||
Havana |
Fix Released
|
Undecided
|
Unassigned |
Bug Description
On list operations, every attribute for every item returned by the plugin is checked by the policy engine to see whether the user has rights to see it [*], assuming the attribute map specifies enforce_policy=True for that attribute
However, in most cases no policies are actually defined for those attributes; in this case the neutron server emits a log.debug statement for the specific attribute saying no policy was found.
This statement is then repeated for every attribute without policy times the number of items in the response.
Simple instrumenation shows list operations take in the API layer more than 500% the time they take in the plugin.
The time is wasted after the plugin call completes and more precisely while doing policy checks.
While other optimisations might be performed (such as not repeating checks already performed, and not triggering init() for each check), the biggest offender is the log statement.
Some measurements are available here: http://
* I believe this is wrong as well, but that's another story
Changed in neutron: | |
milestone: | juno-1 → icehouse-rc2 |
tags: | removed: icehouse-backport-potential |
Changed in neutron: | |
milestone: | icehouse-rc2 → 2014.1 |
Fix proposed to branch: master /review. openstack. org/85299
Review: https:/