Bug #16208
closed
On a loaded system, the compliance computation is fairly expensive
Description
Receiving thousands of reports per second, with 4500 nodes and 321 directive leads to a costly compliance computation
timing_debug log in trace show
[2019-11-18 22:22:24] TRACE debug_timing - Compliance: mergeCompareByRule - unexpected directives computation: 0ms [2019-11-18 22:22:24] TRACE debug_timing - Compliance: mergeCompareByRule - expected directives computation: 0ms [2019-11-18 22:22:24] TRACE debug_timing - Compliance: mergeCompareByRule - prepare data: 0ms [2019-11-18 22:22:24] TRACE debug_timing - Compliance: mergeCompareByRule - get missing reports: 0ms [2019-11-18 22:22:24] TRACE debug_timing - Compliance: mergeCompareByRule - unexpected directives computation: 0ms [2019-11-18 22:22:24] TRACE debug_timing - Compliance: mergeCompareByRule - compute compliance : 1ms [2019-11-18 22:22:24] DEBUG debug_timing - Compliance: mergeCompareByRule global cost : 296ms [2019-11-18 22:22:24] TRACE debug_timing - Compliance: getNodeStatusReports - computing compliance for node NodeId(28e55618-6886-45ed-8992-657a3022e448): 297ms [2019-11-18 22:22:24] TRACE debug_timing - Compliance: computing policy status for NodeId(28e55618-6886-45ed-8992-657a3022e448): 1ms [2019-11-18 22:22:24] TRACE debug_timing - Compliance: Compute complianceForRun map: 268ms [2019-11-18 22:22:24] TRACE debug_timing - Compliance: mergeCompareByRule - prepare data: 0ms [2019-11-18 22:22:24] TRACE debug_timing - Compliance: mergeCompareByRule - get missing reports: 27ms [2019-11-18 22:22:24] TRACE debug_timing - Compliance: mergeCompareByRule - unexpected directives computation: 0ms [2019-11-18 22:22:24] TRACE debug_timing - Compliance: mergeCompareByRule - expected directives computation: 0ms [2019-11-18 22:22:24] TRACE debug_timing - Compliance: mergeCompareByRule - prepare data: 1ms
the Compliance: Compute complianceForRun map part is really expensive, as it iterate over each rules, each directive and each components, and manipulate a lot of collections, changing them and creating them
it's even more complex to debug, as each step in this map is 0ms ...
Updated by Nicolas CHARLES about 5 years ago
a first good step would be to compute the logs not for each step, but for the aggregation of each step within the map creation
Updated by Nicolas CHARLES about 5 years ago
created a unit test to effectively measure with a lot of data
Most of the time seems spend in checkExpectedComponentWithReports
Updated by Nicolas CHARLES about 5 years ago
slashing completely checkExpectedComponentWithReports for tests save 50% of the computation time
Updated by Nicolas CHARLES about 5 years ago
- Status changed from New to In progress
- Assignee set to Nicolas CHARLES
Updated by Nicolas CHARLES about 5 years ago
- Status changed from In progress to Pending technical review
- Assignee changed from Nicolas CHARLES to François ARMAND
- Pull Request set to https://github.com/Normation/rudder/pull/2622
Updated by Nicolas CHARLES about 5 years ago
with these changes, mergeCompareByRule is about 30% faster, the final test going from 11500 ms to 8000ms
Updated by Nicolas CHARLES about 5 years ago
- Status changed from Pending technical review to Pending release
Applied in changeset rudder|de994cd6381043c5d8705270c505b19ea783b634.
Updated by Nicolas CHARLES almost 5 years ago
- Fix check changed from To do to Checked
Updated by Vincent MEMBRÉ almost 5 years ago
- Status changed from Pending release to Released
This bug has been fixed in Rudder 5.0.15 which was released today.