Use less total cpu resources for idl_compiler for faster build on buildbot |
|||
Issue descriptionWhen buildbot runs idl_compiler for target generate_bindings_core_v8_interfaces and generate_bindings_modules_v8_interfaces, it runs idl_compiler around 500 times for both tasks. On buildbot, such invocation sometimes become time consuming in compile step when its incremental build contains diff of some idl files. For example, https://chromium-build-stats.appspot.com/ninja_log/2018/03/13/win69-c4/ninja_log.win69-c4.chrome-bot.20180312-184631.1668.gz/trace.html from https://ci.chromium.org/buildbot/tryserver.chromium.win/win7_chromium_rel_ng/121114 in above build trace, tasks for generating gen/blink/bindings/* are in between 280s ~ 370s and it blocks other tasks running simultaneously. Similar traces are shown in some other builds. https://chromium-build-stats.appspot.com/ninja_log/2018/03/13/win1356-c4/ninja_log.win1356-c4.chrome-bot.20180312-183535.8356.gz/trace.html from https://ci.chromium.org/buildbot/tryserver.chromium.win/win7_chromium_rel_ng/121110 170s ~ 230s is used for generating gen/blink/bindings/* tasks, which makes mojom generator tasks waited due to action pool. https://chromium-build-stats.appspot.com/ninja_log/2018/03/13/win1364-c4/ninja_log.win1364-c4.chrome-bot.20180312-184230.8436.gz/trace.html from https://ci.chromium.org/buildbot/tryserver.chromium.win/win7_chromium_rel_ng/121109 190s ~ 260s is used for generating gen/blink/bindings/* tasks, which makes mojom generator tasks waited due to action pool. For those builds, if we switched from action_foreach to single action in idl_compiler, total cpu resources used by idl_compiler is reduced and other tasks can run simultaneously at the same time. I expect it reduces build time on bot around 1 minute.
,
Mar 13 2018
Run them in parallel or in a single task is one of solutions, and can be a narrow-scope optimization. Doesn't the change regress build time on other trybots or developers? Anyway, I'd like you to investigate more what part is critical to unveil the reason. If paring a file many times is critical, all tasks should be splitted, or we should cache the information. If parallel output is critical, it should be done sequencially, or replacing HDDs with SSDs can be a solution.
,
Mar 13 2018
> Run them in parallel or in a single task is one of solutions, and can be a narrow-scope optimization.
> Doesn't the change regress build time on other trybots or developers?
There are some developers and (probably trybots) seeing slower build in some cases, but single actions has more advantage.
If it speeds up win7_chromium_rel_ng builder (current slowest in tryservers), most of us will have shorter CQ wait time.
> Anyway, I'd like you to investigate more what part is critical to unveil the reason.
> If paring a file many times is critical, all tasks should be splitted, or we should cache the information. If parallel output is critical, it should be done sequencially, or replacing HDDs with SSDs can be a solution.
From the time difference between -j1 with multiple action and single action, I guess there are duplicated execution.
linux: 95.401s (-j1) vs 14.574s (single action)
win: 169.762s (-j1) vs 21.230s (single action)
And overhead of python starting time itself is not ignorable.
tikuta@tikuta:~$ touch empty.py
tikuta@tikuta:~$ time python empty.py
real 0m0.025s
user 0m0.024s
sys 0m0.000s
tikuta@tikuta:~$ time python empty.py
real 0m0.023s
user 0m0.016s
sys 0m0.004s
tikuta@tikuta:~$ time python empty.py
real 0m0.024s
user 0m0.012s
sys 0m0.012s
Running around 1000 idl_compiler.py tasks introduce 23~25 seconds overhead.
I took profile for one of multiple actions and single action.
I couldn't see which function can be smaller bottleneck in single action, but I think some functions can be optimized. (e.g. format_blink_cpp_source_code)
* one of multiple action
tikuta@tikuta:~/chromium/src/out/Release$ python -m cProfile -s cumulative ../../third_party/WebKit/Source/bindings/scripts/idl_compiler.py --cache-dir gen/blink/bindings/scripts --output-dir gen/blink/bindings/core/v8 --info-dir gen/blink/bindings --target-component core ../../third_party/WebKit/Source/core/frame/Window.idl
851262 function calls (828763 primitive calls) in 1.210 seconds
Ordered by: cumulative time
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 1.210 1.210 idl_compiler.py:33(<module>)
1 0.000 0.000 1.148 1.148 idl_compiler.py:182(main)
1 0.000 0.000 1.117 1.117 idl_compiler.py:128(generate_bindings)
1 0.000 0.000 1.106 1.106 idl_compiler.py:124(compile_file)
1 0.000 0.000 1.105 1.105 idl_compiler.py:110(compile_and_write)
1 0.000 0.000 0.875 0.875 code_generator_v8.py:141(generate_code)
1 0.000 0.000 0.868 0.868 code_generator_v8.py:170(generate_code_internal)
1 0.000 0.000 0.868 0.868 code_generator_v8.py:181(generate_interface_code)
1 0.000 0.000 0.699 0.699 code_generator.py:159(render_template)
2 0.000 0.000 0.692 0.346 code_generator.py:127(render_template)
2 0.000 0.000 0.692 0.346 environment.py:974(render)
7163/2 0.010 0.000 0.692 0.346 {method 'join' of 'unicode' objects}
2 0.000 0.000 0.555 0.278 interface.cpp.tmpl:5(root)
2 0.007 0.003 0.552 0.276 interface_base.cpp.tmpl:5(root)
2 0.011 0.005 0.470 0.235 utilities.py:504(format_blink_cpp_source_code)
15067 0.447 0.000 0.447 0.000 {method 'search' of '_sre.SRE_Pattern' objects}
2/1 0.000 0.000 0.227 0.227 idl_reader.py:95(read_idl_definitions)
26 0.000 0.000 0.222 0.009 idl_reader.py:110(read_idl_file)
26 0.000 0.000 0.201 0.008 idl_parser.py:1309(ParseFile)
26 0.000 0.000 0.199 0.008 idl_parser.py:1290(ParseText)
26 0.000 0.000 0.199 0.008 yacc.py:257(parse)
26 0.042 0.002 0.199 0.008 yacc.py:869(parseopt_notrack)
2/1 0.000 0.000 0.187 0.187 interface_dependency_resolver.py:67(resolve_dependencies)
2 0.000 0.000 0.180 0.090 interface_dependency_resolver.py:142(merge_interface_dependencies)
4952/1759 0.010 0.000 0.175 0.000 runtime.py:169(call)
4269/1759 0.009 0.000 0.168 0.000 runtime.py:396(__call__)
1 0.000 0.000 0.167 0.167 v8_interface.py:187(interface_context)
1 0.000 0.000 0.138 0.138 v8_interface.py:512(attributes_context)
553 0.022 0.000 0.137 0.000 v8_attributes.py:49(attribute_context)
2 0.004 0.002 0.136 0.068 interface.h.tmpl:5(root)
~~~ snip ~~~
* single action
tikuta@tikuta:~/chromium/src/out/Release$ python -m cProfile -s cumulative ../../third_party/WebKit/Source/bindings/scripts/idl_compiler.py --cache-dir gen/blink/bindings/scripts --output-dir gen/blink/bindings/core/v8 --info-dir gen/blink/bindings --target-component core --read-idl-list-from-file gen/third_party/WebKit/Source/bindings/core/v8/generate_bindings_core_v8_interfaces_file_list.tmp
10822130 function calls (10606123 primitive calls) in 14.879 seconds
Ordered by: cumulative time
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 14.880 14.880 idl_compiler.py:33(<module>)
1 0.000 0.000 14.822 14.822 idl_compiler.py:182(main)
1 0.001 0.001 14.762 14.762 idl_compiler.py:128(generate_bindings)
548 0.004 0.000 14.752 0.027 idl_compiler.py:124(compile_file)
548 0.003 0.000 14.747 0.027 idl_compiler.py:110(compile_and_write)
548 0.001 0.000 12.784 0.023 code_generator_v8.py:141(generate_code)
548 0.001 0.000 12.688 0.023 code_generator_v8.py:170(generate_code_internal)
453 0.008 0.000 12.191 0.027 code_generator_v8.py:181(generate_interface_code)
548 0.002 0.000 11.168 0.020 code_generator.py:159(render_template)
1096 0.004 0.000 10.993 0.010 code_generator.py:127(render_template)
1096 0.006 0.000 10.989 0.010 environment.py:974(render)
74851/1096 0.088 0.000 10.955 0.010 {method 'join' of 'unicode' objects}
902 0.018 0.000 9.235 0.010 interface.cpp.tmpl:5(root)
902 0.104 0.000 9.076 0.010 interface_base.cpp.tmpl:5(root)
1096 0.198 0.000 6.137 0.006 utilities.py:504(format_blink_cpp_source_code)
285625 5.769 0.000 5.769 0.000 {method 'search' of '_sre.SRE_Pattern' objects}
28388 0.050 0.000 2.382 0.000 environment.py:791(get_template)
28388 0.111 0.000 2.310 0.000 environment.py:768(_load_template)
28402 0.135 0.000 1.919 0.000 loaders.py:167(get_source)
567/548 0.002 0.000 1.891 0.003 idl_reader.py:95(read_idl_definitions)
764 0.005 0.000 1.793 0.002 idl_reader.py:110(read_idl_file)
764 0.008 0.000 1.622 0.002 idl_parser.py:1309(ParseFile)
764 0.004 0.000 1.587 0.002 idl_parser.py:1290(ParseText)
49590/17655 0.091 0.000 1.577 0.000 runtime.py:169(call)
764 0.001 0.000 1.571 0.002 yacc.py:257(parse)
764 0.343 0.000 1.570 0.002 yacc.py:869(parseopt_notrack)
7975/7974 0.012 0.000 1.565 0.000 environment.py:1026(make_module)
44765/16946 0.093 0.000 1.514 0.000 runtime.py:396(__call__)
7975/7974 0.108 0.000 1.477 0.000 environment.py:1089(__init__)
~~~ snip ~~~
,
Mar 13 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/6de84855ecbe01843752e8b0e019c82e5e3a4d0a commit 6de84855ecbe01843752e8b0e019c82e5e3a4d0a Author: Takuto Ikuta <tikuta@google.com> Date: Tue Mar 13 12:32:24 2018 Use single action for idl compiler This is for reducing total cpu consumption by idl_compiler, and let other parallel build tasks can utilize cpu more efficiently. If we use larger -j and modifying idl files frequently, this introduces around 10 seconds build speed regression, but in other cases, this patch has advantage because this lets other generator tasks run simultaneously at the same time. I expect this improves build speed around 20~30 seconds on linux bot and 1 minutes on win bots if the build runs idl_compiler. In buildbot, generating bindings/core/* files took more than 20 seconds (94s ~ 116s in below trace). https://chromium-build-stats.appspot.com/ninja_log/2018/03/12/swarm979-c4/ninja_log.swarm979-c4.chrome-bot.20180311-201738.14539.gz/trace.html from https://ci.chromium.org/p/chromium/builders/luci.chromium.try/linux_chromium_rel_ng/43925 In this 22 seconds, mojom generator tasks are blocked to run. Build trace with this patch shows other tasks run somewhat simultaneously (13s ~ 41s). https://chromium-build-stats.appspot.com/ninja_log/2018/03/12/swarm979-c4/ninja_log.swarm979-c4.chrome-bot.20180311-215549.20798.gz/trace.html from https://ci.chromium.org/p/chromium/builders/luci.chromium.try/linux_chromium_rel_ng/43949 In this 28 seconds, mojom generator tasks can run at the same time. idl_compiler tasks block other tasks around 10 seconds. * for the record With this patch, generate_bindings_core_v8_interfaces took 14.574s on Z840 Linux. Without this patch, on Linux, it took 5.115s with -j48 7.317s with -j16 13.296s with -j8 95.401s with -j1 With this patch, generate_bindings_core_v8_interfaces took 21.230s on Z840 Win10. Without this patch, on Win10, it took 9.460s with -j48 12.086s with -j16 23.497s with -j8 169.762s with -j1 Bug: 821256 Change-Id: Ic3163edfd3cfb4be375e6f24ffc7c11cc9025783 Reviewed-on: https://chromium-review.googlesource.com/958804 Commit-Queue: Takuto Ikuta <tikuta@google.com> Reviewed-by: Kenichi Ishibashi <bashi@chromium.org> Reviewed-by: Hitoshi Yoshida <peria@chromium.org> Cr-Commit-Position: refs/heads/master@{#542775} [modify] https://crrev.com/6de84855ecbe01843752e8b0e019c82e5e3a4d0a/third_party/WebKit/Source/bindings/scripts/scripts.gni
,
Mar 13 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/08220ae24288dd94029b63b432c1e6ca3a363e56 commit 08220ae24288dd94029b63b432c1e6ca3a363e56 Author: Takuto Ikuta <tikuta@google.com> Date: Tue Mar 13 12:46:12 2018 Pruning regexp search in format_blink_cpp_source_code regexp search in format_blink_cpp_source_code is slow. In this patch, I introduced simple pruning to skip time consuming regexp search. Without this patch, generate_bindings_core_v8_interfaces took 12.513s on z840 linux. With this patch, generate_bindings_core_v8_interfaces took 6.562s. Bug: 821256 Change-Id: I3de39d72f4fa8e9f4991a90bc6dd0ba90511e634 Reviewed-on: https://chromium-review.googlesource.com/958810 Reviewed-by: Hitoshi Yoshida <peria@chromium.org> Commit-Queue: Takuto Ikuta <tikuta@google.com> Cr-Commit-Position: refs/heads/master@{#542776} [modify] https://crrev.com/08220ae24288dd94029b63b432c1e6ca3a363e56/third_party/WebKit/Source/bindings/scripts/utilities.py
,
Mar 14 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/9f3b732a24a2989447fe1fea3ebdc908872088e6 commit 9f3b732a24a2989447fe1fea3ebdc908872088e6 Author: Takuto Ikuta <tikuta@google.com> Date: Wed Mar 14 14:18:56 2018 Update Jinja2 from 2.8 to 2.10 This is mainly for taking performance improvement of jinja2. http://jinja.pocoo.org/docs/2.10/changelog/#version-2-10 Manually edited files: README.chromium get_jinja2.sh And I regenerate build/android/test_runner.pydeps * For the record, With Jinja 2.10, running time of idl_compiler for generate_bindings_core_v8_interfaces is like below on Z840 Linux. 5.050s 4.945s 5.077s With Jinja 2.8, running time of idl_compiler for generate_bindings_core_v8_interfaces is like below on Z840 Linux. 6.675s 6.575s 6.574s Bug: 821256 Change-Id: I127e3db94edb22e3ac22a3662872d99b4b91c2a8 Reviewed-on: https://chromium-review.googlesource.com/917930 Reviewed-by: agrieve <agrieve@chromium.org> Reviewed-by: Yuki Shiino <yukishiino@chromium.org> Reviewed-by: Kentaro Hara <haraken@chromium.org> Commit-Queue: Takuto Ikuta <tikuta@google.com> Cr-Commit-Position: refs/heads/master@{#543075} [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/build/android/test_runner.pydeps [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/AUTHORS [add] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/Jinja2-2.10.tar.gz.md5 [add] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/Jinja2-2.10.tar.gz.sha512 [delete] https://crrev.com/b3242253735182e33981db7588be8645eafcc6d9/third_party/jinja2/Jinja2-2.8.tar.gz.md5 [delete] https://crrev.com/b3242253735182e33981db7588be8645eafcc6d9/third_party/jinja2/Jinja2-2.8.tar.gz.sha512 [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/README.chromium [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/__init__.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/_compat.py [add] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/_identifier.py [delete] https://crrev.com/b3242253735182e33981db7588be8645eafcc6d9/third_party/jinja2/_stringdefs.py [add] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/asyncfilters.py [add] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/asyncsupport.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/bccache.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/compiler.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/constants.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/debug.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/defaults.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/environment.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/exceptions.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/ext.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/filters.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/get_jinja2.sh [add] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/idtracking.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/jinja2.gni [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/lexer.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/loaders.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/meta.py [add] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/nativetypes.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/nodes.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/optimizer.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/parser.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/runtime.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/sandbox.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/tests.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/utils.py [modify] https://crrev.com/9f3b732a24a2989447fe1fea3ebdc908872088e6/third_party/jinja2/visitor.py
,
Mar 14 2018
,
Mar 15 2018
|
|||
►
Sign in to add a comment |
|||
Comment 1 by bashi@chromium.org
, Mar 13 2018