Project

General

Profile

Bug #13987

Massive performance penalty in policy generation due to invalid usage of StringTemplate

Added by Nicolas CHARLES 7 months ago. Updated 6 months ago.

Status:
Released
Priority:
N/A
Category:
Performance and scalability
Target version:
Severity:
User visibility:
Effort required:
Priority:
0

Description

We are using String Template in a non efficient way: for each node, for each template, we are re-tokenizing the template
We should instead use a copy of the tokenized version (as sescribed in https://theantlrguy.atlassian.net/wiki/spaces/ST/pages/1409053/ST+condensed+--+Templates+and+groups)

Perf increase is quite impressive:
Without cache of tokenization

[2018-12-17 17:17:42] INFO  policy.generation - Build target configuration    :       8914 ms
[2018-12-17 17:17:42] INFO  policy.generation - Write node configurations     :      84801 ms
[2018-12-17 17:17:42] INFO  policy.generation - Save expected reports         :        785 ms
[2018-12-17 17:17:42] INFO  policy.generation - Run post generation hooks     :         67 ms
[2018-12-17 17:17:42] INFO  policy.generation - Number of nodes updated       :       1597  
[2018-12-17 17:17:42] INFO  policy.generation - StringTemplate related stats: total time of new StringTemplate     :      54574 ms  
[2018-12-17 17:17:42] INFO  policy.generation - StringTemplate related stats: total time of replacement of var     :        467 ms  
[2018-12-17 17:17:42] INFO  policy.generation - StringTemplate related stats: nbTemaplte    :      60110    
[2018-12-17 17:17:42] INFO  policy.generation - Policy generation completed in:     109967 ms

With cache of tokenization

[2018-12-17 17:12:27] INFO  policy.generation - Build target configuration    :       8114 ms
[2018-12-17 17:12:27] INFO  policy.generation - Write node configurations     :      30503 ms
[2018-12-17 17:12:27] INFO  policy.generation - Save expected reports         :        781 ms
[2018-12-17 17:12:27] INFO  policy.generation - Run post generation hooks     :         91 ms
[2018-12-17 17:12:27] INFO  policy.generation - Number of nodes updated       :       1597  
[2018-12-17 17:12:27] INFO  policy.generation - StringTemplate related stats: total time of new StringTemplate     :        293 ms  
[2018-12-17 17:12:27] INFO  policy.generation - StringTemplate related stats: total time of replacement of var     :        430 ms  
[2018-12-17 17:12:27] INFO  policy.generation - StringTemplate related stats: nbTemaplte    :      60110    
[2018-12-17 17:12:27] INFO  policy.generation - Policy generation completed in:      57362 ms

we can contemplate a *2 perf increase


Files

with.png (67.9 KB) with.png with the patch Nicolas CHARLES, 2018-12-17 23:15
without.png (82.7 KB) without.png without the patch Nicolas CHARLES, 2018-12-17 23:15

Related issues

Related to Rudder - Bug #14322: Directive parameter values are mixed between directivesReleasedActions

Associated revisions

Revision 22dd0b62 (diff)
Added by Nicolas CHARLES 7 months ago

Fixes #13987: Massive performance penalty in policy generation due to invalid usage of StringTemplate

History

#1

Updated by Nicolas CHARLES 7 months ago

  • Status changed from New to In progress
  • Assignee set to Nicolas CHARLES
#2

Updated by Nicolas CHARLES 7 months 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/2098
#3

Updated by Rudder Quality Assistant 7 months ago

  • Status changed from Pending technical review to Discussion
  • Assignee changed from François ARMAND to Nicolas CHARLES
#4

Updated by Nicolas CHARLES 7 months ago

  • Status changed from Discussion to Pending technical review
  • Assignee changed from Nicolas CHARLES to François ARMAND
#5

Updated by Nicolas CHARLES 7 months ago

More details: after 3 full policy generation, with 1600 nodes

[2018-12-17 22:58:33] INFO  policy.generation - Timing summary:
[2018-12-17 22:58:33] INFO  policy.generation - Run pre-gen scripts hooks     :          0 ms
[2018-12-17 22:58:33] INFO  policy.generation - Run pre-gen modules hooks     :          0 ms
[2018-12-17 22:58:33] INFO  policy.generation - Fetch all information         :        162 ms
[2018-12-17 22:58:33] INFO  policy.generation - Historize names               :        577 ms
[2018-12-17 22:58:33] INFO  policy.generation - Build current rule values     :         43 ms
[2018-12-17 22:58:33] INFO  policy.generation - Build target configuration    :       7184 ms
[2018-12-17 22:58:33] INFO  policy.generation - Write node configurations     :      17176 ms
[2018-12-17 22:58:33] INFO  policy.generation - Save expected reports         :        704 ms
[2018-12-17 22:58:33] INFO  policy.generation - Run post generation hooks     :          5 ms
[2018-12-17 22:58:33] INFO  policy.generation - Number of nodes updated       :       1597   
[2018-12-17 22:58:33] INFO  policy.generation - Policy generation completed in:      41858 ms

before

[2018-12-17 23:09:30] INFO  policy.generation - Run pre-gen scripts hooks     :          0 ms
[2018-12-17 23:09:30] INFO  policy.generation - Run pre-gen modules hooks     :          0 ms
[2018-12-17 23:09:30] INFO  policy.generation - Fetch all information         :        151 ms
[2018-12-17 23:09:30] INFO  policy.generation - Historize names               :        472 ms
[2018-12-17 23:09:30] INFO  policy.generation - Build current rule values     :         52 ms
[2018-12-17 23:09:30] INFO  policy.generation - Build target configuration    :       8278 ms
[2018-12-17 23:09:30] INFO  policy.generation - Write node configurations     :      33907 ms
[2018-12-17 23:09:30] INFO  policy.generation - Save expected reports         :        747 ms
[2018-12-17 23:09:30] INFO  policy.generation - Run post generation hooks     :          5 ms
[2018-12-17 23:09:30] INFO  policy.generation - Number of nodes updated       :       1597   
[2018-12-17 23:09:30] INFO  policy.generation - Policy generation completed in:      57950 ms

So the step "Write node configurations" is twice as fast with this, and the overall policy generation is 30% faster. This improvement scales with the number of directives used - so the larger the configuration, the better the improvement is.

Attached, the visualvm of the policy generation, with this modification and without - the difference in total memory is most likely due to difference in compliance

#6

Updated by Nicolas CHARLES 7 months ago

  • Status changed from Discussion to Pending technical review
  • Assignee changed from Nicolas CHARLES to François ARMAND
#7

Updated by Rudder Quality Assistant 7 months ago

  • Status changed from Pending technical review to Discussion
  • Assignee changed from François ARMAND to Nicolas CHARLES
#8

Updated by Nicolas CHARLES 7 months ago

  • Status changed from Discussion to Pending technical review
  • Assignee changed from Nicolas CHARLES to François ARMAND
#9

Updated by Nicolas CHARLES 7 months ago

  • Status changed from Pending technical review to Pending release
#10

Updated by Vincent MEMBRÉ 6 months ago

  • Status changed from Pending release to Released
This bug has been fixed in Rudder 4.3.8 and 5.0.4 which were released today.
Changelog
Changelog
#11

Updated by Nicolas CHARLES 5 months ago

  • Related to Bug #14322: Directive parameter values are mixed between directives added

Also available in: Atom PDF