Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fixes #16892: Upgrade to ZIO RC18 #2817

Merged
merged 1 commit into from Mar 16, 2020

Conversation

fanf
Copy link
Member

@fanf fanf commented Mar 10, 2020

https://issues.rudder.io/issues/16892

Switch to RC18-1. Use https://docs.google.com/document/d/1P0mx1gSNU2UTi-9PXUeY8O74v5gyK-UETznM1SbkQjA/edit#heading=h.37bbueaecc51

Firs commit, make it compiles and tests pass. Middle commit: trivial changes.
Last commit: use ZIO default threadpool for blocking.

Main changes:

  • ZSchedule is renamed Schedule;

  • traverse if renamed into foreach and sequence into collectAll;

  • .succeed and .fail are deleted => create an implicit for them;

  • use forkDaemon whenever (== almost always) the fiber should be a daemon and is not joined;

  • Change ZioCommon#internal to reflect changes with ZLayer. Now the runtime is built by hand, and we initialize the environment by using it to get ZLayer[Any, Nothing, ZEnv] in place of
    ZManaged[Any, ZLayer[...]]. ZEnv is clock, blocking, console, etc. So we have access to all that;
    ZLayer presentation: https://github.com/adamgfraser/solving-the-dependency-injection-problem-with-zio/blob/master/solving-the-dependency-injection-problem-with-zio.pdf

  • provide is replaced by provideLayer to use ZLayer.

  • use ZIO default threadpool for Platform as it is consistently (on my machine) 20% faster than our.

@fanf fanf requested a review from ncharles March 10, 2020 08:15
@fanf fanf added WIP Use that label for a Work In Progress PR that must not be merged yet qa: Can't merge and removed qa: Can't merge labels Mar 10, 2020
@fanf
Copy link
Member Author

fanf commented Mar 10, 2020

PR updated with a new commit

1 similar comment
@fanf
Copy link
Member Author

fanf commented Mar 10, 2020

PR updated with a new commit

@fanf
Copy link
Member Author

fanf commented Mar 10, 2020

PR updated with a new commit


final def makeDefault(yieldOpCount: Int): Executor =
Executor.fromThreadPoolExecutor(_ => yieldOpCount) {
val corePoolSize = Runtime.getRuntime.availableProcessors() * 2
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

why twice the number of core ? is it documented somewhere the reasoning ?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actually, we don't use it at all anymore. I think it was just for tests.
The reasoning was: we have a lot of threads used to process blocking fiber, and most of them actually block. So it is reasonnable to have a core pool size of CPUx2, given most of them will be block often.
In practice, IIRC, it worked well for small number of CPU, but for more (like 16), it was a bit too big.

@fanf
Copy link
Member Author

fanf commented Mar 10, 2020

PR updated with a new commit

@fanf fanf force-pushed the arch_16892/upgrade_to_zio_rc18 branch from 230d2c1 to a650023 Compare March 12, 2020 14:31
@fanf
Copy link
Member Author

fanf commented Mar 12, 2020

PR updated with a new commit

@fanf
Copy link
Member Author

fanf commented Mar 12, 2020

UPDATE: the last version (RC18-2) brings back direct access to environment services which don't have a special build/finish logic (so all of ZEnv), which allows to minimize changes. ZLayer are of course still their.

@fanf
Copy link
Member Author

fanf commented Mar 12, 2020

PR updated with a new commit

1 similar comment
@fanf
Copy link
Member Author

fanf commented Mar 12, 2020

PR updated with a new commit

@fanf fanf removed the WIP Use that label for a Work In Progress PR that must not be merged yet label Mar 13, 2020
@ncharles
Copy link
Member

Performance impact is really significative

Master
DEBUG policy.generation.timing - All relevant information fetched in 4777 ms, start names historization.
Xmx:17.6 GB nodes:4549 (cached:0) rules:157 (enabled:156) techniques:50 (enabled:50) directives:325 (enabled:325) groups:454 (dynamic:454) parameters:2
DEBUG policy.generation.timing - Historization of names done in 5626 ms, start to build rule values.
DEBUG policy.generation.timing - RuleVals built in 2203 ms, start to expand their values.
DEBUG policy.generation.timing - Node contexts built in 64807 ms, start to build new node configurations.
TRACE policy.generation.timing.buildNodeConfig - - create filtered policy drafts: 46 ms
TRACE policy.generation.timing.buildNodeConfig - - compile global and nodes paramaters: 222 ms
TRACE policy.generation.timing.buildNodeConfig - - created bounded policy drafts: 794766 ms (number of drafts: 607850)
TRACE policy.generation.timing.buildNodeConfig - - - expand parameter: 81815 ms
TRACE policy.generation.timing.buildNodeConfig - - - evaluate JS: 675395 (number of evaluation: 6868792)
TRACE policy.generation.timing.buildNodeConfig - - merge policy draft to get policies: 38665 ms
DEBUG policy.generation.timing.buildNodeConfig - Total run config: 167065 ms
DEBUG policy.generation.timing - Node's target configuration built in 167479 ms, start to update rule values.
INFO policy.generation - Configuration of 4549 nodes were updated, their policies are going to be written
DEBUG policy.generation.timing - 60 promises templates read in 281 ms
DEBUG policy.generation.timing - 63 promises resources read in 247 ms
DEBUG policy.generation.timing - Paths computed and templates read in 576 ms
DEBUG policy.generation.timing - Policy templates prepared in 16591 ms
TRACE policy.generation.timing - -> bundle sequence built in 17823 ms | agent system variables built in 5249 ms | policy template prepared in 59301 ms
DEBUG policy.generation.timing - Policies written in 745447 ms
TRACE policy.generation.timing - -> fill template: 421394 ms [fill template: 84324 ms | to string template: 330917 ms | fill template wait: 0 ms | get template exec: 144 ms | get template wait: 0 ms]
TRACE policy.generation.timing - -> write template: 466162 ms | copy resources: 17559 ms | agent specific: 6696 ms | write CSV: 17559 ms| write JSON: 29851 ms
DEBUG policy.generation.timing - Getting info for timing trace in 2 ms
DEBUG policy.generation.timing - Properties written in 2139 ms
DEBUG policy.generation.timing - Parameters written in 1591 ms
DEBUG policy.generation.timing.hooks - Hooks for policy-generation-node-ready executed in 22852 ms
DEBUG policy.generation - Using atomic move for node policies
DEBUG policy.generation.timing - Policies moved to their final position in 56423 ms
DEBUG policy.generation.timing.hooks - Hooks for policy-generation-node-finished executed in 996 ms
DEBUG policy.generation.timing - Node configuration written on filesystem in 846681 ms
DEBUG policy.generation.timing - Node configuration cached in LDAP in 21477 ms
DEBUG policy.generation.timing - Node configuration written in 868162 ms, start to update expected reports.
DEBUG policy.generation.timing - Reports computed in 2196 ms
DEBUG policy.generation.timing - Node expected reports saved in base in 34759 ms.
DEBUG policy.generation.timing - Post-policy-generation hooks ran in 537 ms
INFO policy.generation.timing - Timing summary:
INFO policy.generation.timing - Run pre-gen scripts hooks : 7 ms
INFO policy.generation.timing - Run pre-gen modules hooks : 0 ms
INFO policy.generation.timing - Fetch all information : 4777 ms
INFO policy.generation.timing - Historize names : 5626 ms
INFO policy.generation.timing - Build current rule values : 2203 ms
INFO policy.generation.timing - Build target configuration : 167479 ms
INFO policy.generation.timing - Write node configurations : 868162 ms
INFO policy.generation.timing - Save expected reports : 2196 ms
INFO policy.generation.timing - Run post generation hooks : 537 ms
INFO policy.generation.timing - Number of nodes updated : 4549
INFO policy.generation.timing - Policy generation succeeded in: 19 min 31 s

This branch

Xmx:17.6 GB nodes:4549 (cached:0) rules:157 (enabled:156) techniques:50 (enabled:50) directives:325 (enabled:325) groups:454 (dynamic:454) parameters:2
DEBUG policy.generation.timing - Historization of names done in 3878 ms, start to build rule values.
DEBUG policy.generation.timing - RuleVals built in 1429 ms, start to expand their values.
DEBUG policy.generation.timing - Node contexts built in 61169 ms, start to build new node configurations.
TRACE policy.generation.timing.buildNodeConfig - - create filtered policy drafts: 36 ms
TRACE policy.generation.timing.buildNodeConfig - - compile global and nodes paramaters: 164 ms
TRACE policy.generation.timing.buildNodeConfig - - created bounded policy drafts: 818664 ms (number of drafts: 607850)
TRACE policy.generation.timing.buildNodeConfig - - - expand parameter: 79839 ms
TRACE policy.generation.timing.buildNodeConfig - - - evaluate JS: 701115 (number of evaluation: 6868792)
TRACE policy.generation.timing.buildNodeConfig - - merge policy draft to get policies: 38062 ms
DEBUG policy.generation.timing.buildNodeConfig - Total run config: 171607 ms
DEBUG policy.generation.timing - Node's target configuration built in 172009 ms, start to update rule values.
INFO policy.generation - Configuration of 4549 nodes were updated, their policies are going to be written
DEBUG policy.generation.timing - 60 promises templates read in 354 ms
DEBUG policy.generation.timing - 63 promises resources read in 193 ms
DEBUG policy.generation.timing - Paths computed and templates read in 606 ms
DEBUG policy.generation.timing - Policy templates prepared in 14302 ms
TRACE policy.generation.timing - -> bundle sequence built in 11344 ms | agent system variables built in 215 ms | policy template prepared in 59173 ms
DEBUG policy.generation.timing - Policies written in 449650 ms
TRACE policy.generation.timing - -> fill template: 263522 ms [fill template: 63850 ms | to string template: 193949 ms | fill template wait: 0 ms | get template exec: 51 ms | get template wait: 0 ms]
TRACE policy.generation.timing - -> write template: 344890 ms | copy resources: 73183 ms | agent specific: 213 ms | write CSV: 73183 ms| write JSON: 79561 ms
DEBUG policy.generation.timing - Getting info for timing trace in 1 ms
DEBUG policy.generation.timing - Properties written in 1431 ms
DEBUG policy.generation.timing - Parameters written in 959 ms
DEBUG policy.generation.timing.hooks - Hooks for policy-generation-node-ready executed in 116792 ms
DEBUG policy.generation - Using atomic move for node policies
DEBUG policy.generation.timing - Policies moved to their final position in 51801 ms
DEBUG policy.generation.timing.hooks - Hooks for policy-generation-node-finished executed in 426 ms
DEBUG policy.generation.timing - Node configuration written on filesystem in 636071 ms
DEBUG policy.generation.timing - Node configuration cached in LDAP in 19016 ms
DEBUG policy.generation.timing - Node configuration written in 655090 ms, start to update expected reports.
DEBUG policy.generation.timing - Reports computed in 2132 ms
DEBUG policy.generation.timing - Node expected reports saved in base in 34860 ms.
DEBUG policy.generation.timing - Post-policy-generation hooks ran in 550 ms
INFO policy.generation.timing - Timing summary:
INFO policy.generation.timing - Run pre-gen scripts hooks : 2 ms
INFO policy.generation.timing - Run pre-gen modules hooks : 0 ms
INFO policy.generation.timing - Fetch all information : 2977 ms
INFO policy.generation.timing - Historize names : 3878 ms
INFO policy.generation.timing - Build current rule values : 1429 ms
INFO policy.generation.timing - Build target configuration : 172009 ms
INFO policy.generation.timing - Write node configurations : 655090 ms
INFO policy.generation.timing - Save expected reports : 2132 ms
INFO policy.generation.timing - Run post generation hooks : 550 ms
INFO policy.generation.timing - Number of nodes updated : 4549
INFO policy.generation.timing - Policy generation succeeded in: 15 min 59 s

To StringTemplate is twice as fast, yet copy ressources and write csv are much slower (and have same length in both, so it may be a logging bug)

For the record, branch 6.0 is

Xmx:17.6 GB nodes:4549 (cached:0) rules:157 (enabled:156) techniques:50 (enabled:50) directives:325 (enabled:325) groups:454 (dynamic:454) parameters:2
DEBUG policy.generation.timing - Historization of names done in 3865 ms, start to build rule values.
DEBUG policy.generation.timing - RuleVals built in 2408 ms, start to expand their values.
DEBUG policy.generation.timing - Node contexts built in 65466 ms, start to build new node configurations.
TRACE policy.generation.timing.buildNodeConfig - - create filtered policy drafts: 46 ms
TRACE policy.generation.timing.buildNodeConfig - - compile global and nodes paramaters: 227 ms
TRACE policy.generation.timing.buildNodeConfig - - created bounded policy drafts: 753356 ms (number of drafts: 607850)
TRACE policy.generation.timing.buildNodeConfig - - - expand parameter: 77774 ms
TRACE policy.generation.timing.buildNodeConfig - - - evaluate JS: 638645 (number of evaluation: 6868792)
TRACE policy.generation.timing.buildNodeConfig - - merge policy draft to get policies: 39596 ms
DEBUG policy.generation.timing.buildNodeConfig - Total run config: 159061 ms
DEBUG policy.generation.timing - Node's target configuration built in 159359 ms, start to update rule values.
INFO policy.generation - Configuration of 4549 nodes were updated, their policies are going to be written
DEBUG policy.generation.timing - 60 promises templates read in 269 ms
DEBUG policy.generation.timing - 63 promises resources read in 248 ms
DEBUG policy.generation.timing - Paths computed and templates read in 554 ms
DEBUG policy.generation.timing - Policy templates prepared in 17035 ms
TRACE policy.generation.timing - -> bundle sequence built in 17607 ms | agent system variables built in 5727 ms | policy template prepared in 61208 ms
DEBUG policy.generation.timing - Policies written in 752061 ms
TRACE policy.generation.timing - -> fill template: 401283 ms [fill template: 80058 ms | to string template: 314619 ms | fill template wait: 0 ms | get template exec: 126 ms | get template wait: 0 ms]
TRACE policy.generation.timing - -> write template: 496022 ms | copy resources: 17672 ms | agent specific: 2912 ms | write CSV: 17672 ms| write JSON: 34164 ms
DEBUG policy.generation.timing - Getting info for timing trace in 2 ms
DEBUG policy.generation.timing - Properties written in 2384 ms
DEBUG policy.generation.timing - Parameters written in 1418 ms
DEBUG policy.generation.timing.hooks - Hooks for policy-generation-node-ready executed in 26971 ms
DEBUG policy.generation - Using atomic move for node policies
DEBUG policy.generation.timing - Policies moved to their final position in 46638 ms
DEBUG policy.generation.timing.hooks - Hooks for policy-generation-node-finished executed in 1022 ms
DEBUG policy.generation.timing - Node configuration written on filesystem in 848148 ms
DEBUG policy.generation.timing - Node configuration cached in LDAP in 17712 ms
DEBUG policy.generation.timing - Node configuration written in 865863 ms, start to update expected reports.
DEBUG policy.generation.timing - Reports computed in 2051 ms
DEBUG policy.generation.timing - Node expected reports saved in base in 31709 ms.
DEBUG policy.generation.timing - Post-policy-generation hooks ran in 572 ms
INFO policy.generation.timing - Timing summary:
INFO policy.generation.timing - Run pre-gen scripts hooks : 2 ms
INFO policy.generation.timing - Run pre-gen modules hooks : 0 ms
INFO policy.generation.timing - Fetch all information : 3819 ms
INFO policy.generation.timing - Historize names : 3865 ms
INFO policy.generation.timing - Build current rule values : 2408 ms
INFO policy.generation.timing - Build target configuration : 159359 ms
INFO policy.generation.timing - Write node configurations : 865863 ms
INFO policy.generation.timing - Save expected reports : 2051 ms
INFO policy.generation.timing - Run post generation hooks : 572 ms
INFO policy.generation.timing - Number of nodes updated : 4549
INFO policy.generation.timing - Policy generation succeeded in: 19 min 18 s

@fanf
Copy link
Member Author

fanf commented Mar 16, 2020

@ncharles : copy resources / csv is a bug:

 timingLogger.trace(s" -> write template: ${w} ms | copy resources: ${c} ms | agent specific: ${a} ms | write CSV: ${c} ms| write JSON: ${j} ms")

Both uses c when resources is r :/

@Normation-Quality-Assistant
Copy link
Contributor

This PR is not mergeable to upper versions.
Since it is "Ready for merge" you must merge it by yourself using the following command:
rudder-dev merge https://github.com/Normation/rudder/pull/2817
-- Your faithful QA
Kant merge: "Two things awe me most, the starry sky above me and the moral law within me."
(https://ci.normation.com/jenkins/job/merge-accepted-pr/21519/console)

@fanf
Copy link
Member Author

fanf commented Mar 16, 2020

OK, squash merging this PR

@fanf fanf force-pushed the arch_16892/upgrade_to_zio_rc18 branch from 62d98f9 to 8c76aa3 Compare March 16, 2020 14:04
@fanf fanf merged commit 8c76aa3 into Normation:master Mar 16, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
3 participants