Uh oh!
There was an error while loading. Please reload this page.
- Notifications
You must be signed in to change notification settings - Fork 34k
GH-130090: build time analysis#131005
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
Uh oh!
There was an error while loading. Please reload this page.
GH-130090: build time analysis #131005
Changes from all commits
859c89fa529c3926fb51f6e2cb697b46aebced66bd1aae65d52fd5abc2ecb57ad72df574ec74e79ce4188c8aa792a9da27ea4de963346b9d9db1a290e6f95f0bd337d981210be1dfc399879c49File filter
Filter by extension
Conversations
Uh oh!
There was an error while loading. Please reload this page.
Jump to
Uh oh!
There was an error while loading. Please reload this page.
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -504,6 +504,7 @@ Grant Edwards | ||
| Vlad Efanov | ||
| Zvi Effron | ||
| John Ehresman | ||
| Chris Eibl | ||
| Tal Einat | ||
| Eric Eisner | ||
| Andrew Eland | ||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,2 @@ | ||
| Building with ``PlatformToolset=ClangCL`` on Windows now supports PGO | ||
| (profile guided optimization). Patch by Chris Eibl. |
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,263 @@ | ||
| import argparse | ||
MemberAuthor There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Not a beauty but it creates the tables for me :) | ||
| import glob | ||
| import re | ||
| from dataclasses import dataclass | ||
| from datetime import datetime, date, time | ||
| # Verstrichene Zeit 00:00:00.74 | ||
| msbuild_time_str = "Verstrichene Zeit" | ||
MemberAuthor There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. That's the thing I dislike most: msbuild does this localized :( | ||
| # Total duration: 1 min 15 sec | ||
| pgo_time_str = "Total duration:" | ||
| pgo_regex = re.compile( | ||
| r"%s\s(\d{1,2})\smin\s(\d{1,2})\ssec" % pgo_time_str) | ||
| begin_ts_str = "BeginTimeStamp" | ||
| end_ts_str = "EndTimeStamp" | ||
| # ReSTTable and MarkDownTable shamelessly taken from pyperf | ||
| class ReSTTable: | ||
| def __init__(self, headers, rows): | ||
| self.headers = headers | ||
| self.rows = rows | ||
| self.widths = [len(header) for header in self.headers] | ||
| for row in self.rows: | ||
| for column, cell in enumerate(row): | ||
| self.widths[column] = max(self.widths[column], len(cell)) | ||
| def _render_line(self, char='-'): | ||
| parts = [''] | ||
| for width in self.widths: | ||
| parts.append(char * (width + 2)) | ||
| parts.append('') | ||
| return '+'.join(parts) | ||
| def _render_row(self, row): | ||
| parts = [''] | ||
| for width, cell in zip(self.widths, row): | ||
| parts.append(' %s ' % cell.ljust(width)) | ||
| parts.append('') | ||
| return '|'.join(parts) | ||
| def render(self, write_line): | ||
| write_line(self._render_line('-')) | ||
| write_line(self._render_row(self.headers)) | ||
| write_line(self._render_line('=')) | ||
| for row in self.rows: | ||
| write_line(self._render_row(row)) | ||
| write_line(self._render_line('-')) | ||
| class MarkDownTable: | ||
| def __init__(self, headers, rows): | ||
| self.headers = headers | ||
| self.rows = rows | ||
| self.widths = [len(header) for header in self.headers] | ||
| for row in self.rows: | ||
| for column, cell in enumerate(row): | ||
| self.widths[column] = max(self.widths[column], len(cell)) | ||
| def _render_line(self, char='-'): | ||
| parts = [''] | ||
| for idx, width in enumerate(self.widths): | ||
| if idx == 0: | ||
| parts.append(char * (width + 2)) | ||
| else: | ||
| parts.append(f':{char * width}:') | ||
| parts.append('') | ||
| return '|'.join(parts) | ||
| def _render_row(self, row): | ||
| parts = [''] | ||
| for width, cell in zip(self.widths, row): | ||
| parts.append(" %s " % cell.ljust(width)) | ||
| parts.append('') | ||
| return '|'.join(parts) | ||
| def render(self, write_line): | ||
| write_line(self._render_row(self.headers)) | ||
| write_line(self._render_line('-')) | ||
| for row in self.rows: | ||
| write_line(self._render_row(row)) | ||
| @dataclass | ||
| class Build: | ||
| name: str | ||
| build_times: list | ||
| project_times: dict | ||
| @dataclass | ||
| class PgoBuild: | ||
| name: str | ||
| build_times: list | ||
| project_times_pginstrument: dict | ||
| project_times_pgupdate: dict | ||
| def get_secs_from_pgo(t): | ||
| m = pgo_regex.match(t) | ||
| return float(m[1]) * 60.0 + float(m[2]) | ||
| def get_secs_from_msbuild(t): | ||
| t = t[len(msbuild_time_str):].strip() | ||
| secs = (datetime.combine(date.min, time.fromisoformat(t)) | ||
| - datetime.min).total_seconds() | ||
| return secs | ||
| def read_build(filepath): | ||
| with open(build_name) as fh: | ||
| content = fh.read() | ||
| return pgo_time_str in content, content.splitlines() | ||
| def dump_summary(builds, args): | ||
| if not builds: | ||
| return | ||
| num_builds = len(builds[0].build_times) | ||
| is_pgo = num_builds > 1 | ||
| headers = [""] | ||
| rows = [] | ||
| for i in range(num_builds): | ||
| row = [i] * (len(builds) + 1) | ||
| rows.append(row) | ||
| if is_pgo: | ||
| for i, n in enumerate(("pginstr", "pgo", "kill", "pgupd", "total time")): | ||
| rows[i][0] = n | ||
| else: | ||
| rows[0][0] = "total time" | ||
| for x, build in enumerate(builds): | ||
| headers.append(build.name) | ||
| for y, t in enumerate(build.build_times): | ||
| rows[y][x + 1] = "%6.1f" % t | ||
| if args.table_format == "rest": | ||
| table = ReSTTable(headers, rows) | ||
| else: | ||
| table = MarkDownTable(headers, rows) | ||
| if is_pgo: | ||
| print("\nPGO builds:") | ||
| else: | ||
| print("\nDebug and release builds:") | ||
| table.render(print) | ||
| def dump_details(builds, args): | ||
| if not builds: | ||
| return | ||
| if hasattr(builds[0], "project_times"): | ||
| attrs = ["project_times"] | ||
| else: | ||
| attrs = ["project_times_pginstrument", "project_times_pgupdate"] | ||
| is_pgo = len(attrs) > 1 | ||
| for attr in attrs: | ||
| proj_first_build = getattr(builds[0], attr) | ||
| headers = [""] | ||
| rows = [] | ||
| k = list(proj_first_build.keys()) | ||
| # dict is ordered :) | ||
| # thus, we get here _freeze_module and python314 ... | ||
| skip = set(k[0:2]) | ||
| # ... plus total | ||
| skip.add(k[-1]) | ||
| cpy ={k: v for k, v in proj_first_build.items() if k not in skip} | ||
| order = k[0:2] + list([name for name, val in sorted( | ||
| cpy.items(), key=lambda item: item[1], reverse=True)]) | ||
| order.append(k[-1]) | ||
| for i in range(len(proj_first_build)): | ||
| row = [i] * (len(builds) + 1) | ||
| rows.append(row) | ||
| for i, n in enumerate(order): | ||
| rows[i][0] = n | ||
| for x, build in enumerate(builds): | ||
| headers.append(build.name) | ||
| for y, n in enumerate(order): | ||
| rows[y][x + 1] = "%6.1f" % getattr(build, attr)[n] | ||
| if args.table_format == "rest": | ||
| table = ReSTTable(headers, rows) | ||
| else: | ||
| table = MarkDownTable(headers, rows) | ||
| if is_pgo: | ||
| print("\nDetails %s:" % attr.replace("project_times_", "")) | ||
| else: | ||
| print("\nDetails:") | ||
| table.render(print) | ||
| if __name__ == "__main__": | ||
| parser = argparse.ArgumentParser(description='Display build times.') | ||
| parser.add_argument( | ||
| "--table-format", type=str, default="rest", choices=["rest", "md"], | ||
| help="Format of table rendering") | ||
| parser.add_argument( | ||
| 'filenames', metavar='build_log.txt', type=str, nargs='*', | ||
| help='Build logs to process. Defaults to globbing build_*.txt') | ||
| args = parser.parse_args() | ||
| if len(args.filenames) == 0: | ||
| filenames = sorted(glob.glob("build_*.txt")) | ||
| elif len(args.filenames) == 1: | ||
| filenames = sorted(glob.glob(args.filenames[0])) | ||
| else: | ||
| filenames = args.filenames | ||
| builds = [] | ||
| pgo_builds = [] | ||
| proj_begin_ts ={} | ||
| for build_name in filenames: | ||
| is_pgo_build, lines = read_build(build_name) | ||
| build_name = build_name.replace("build_", "") | ||
| build_name = build_name.replace(".txt", "") | ||
| if is_pgo_build: | ||
| build = PgoBuild(build_name, [],{},{}) | ||
| pgo_builds.append(build) | ||
| project_times = build.project_times_pginstrument | ||
| else: | ||
| build = Build(build_name, [],{}) | ||
| builds.append(build) | ||
| project_times = build.project_times | ||
| for line in lines: | ||
| line = line.strip() | ||
| if len(build.build_times) > 1: | ||
| project_times = build.project_times_pgupdate | ||
| if line.startswith(msbuild_time_str): | ||
| secs = get_secs_from_msbuild(line) | ||
| build.build_times.append(secs) | ||
| elif line.startswith(pgo_time_str): | ||
| secs = get_secs_from_pgo(line) | ||
| build.build_times.append(secs) | ||
| elif line.startswith(begin_ts_str): | ||
| proj, begin_ts = line[len(begin_ts_str):].strip().split(":") | ||
| if proj.endswith("_d"): | ||
| proj = proj[:-2] | ||
| proj_begin_ts[proj] = begin_ts | ||
| elif line.startswith(end_ts_str): | ||
| proj, end_ts = line[len(end_ts_str):].strip().split(":") | ||
| if proj.endswith("_d"): | ||
| proj = proj[:-2] | ||
| try: | ||
| begin_ts = proj_begin_ts.pop(proj) | ||
| except KeyError: | ||
| raise Exception( | ||
| "end for %r but no begin" % proj) | ||
| project_times[proj] = float(end_ts) - float(begin_ts) | ||
| project_times["total"] = sum(project_times.values()) | ||
| if is_pgo_build: | ||
| build.project_times_pginstrument["total"] = sum( | ||
| build.project_times_pginstrument.values()) | ||
| build.build_times.append(sum(build.build_times)) | ||
| dump_summary(builds, args) | ||
| dump_summary(pgo_builds, args) | ||
| dump_details(builds, args) | ||
| dump_details(pgo_builds, args) | ||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,48 @@ | ||
| <?xml version="1.0" encoding="utf-8"?> | ||
| <Project ToolsVersion="15.0" xmlns="http://schemas.microsoft.com/developer/msbuild/2003"> | ||
| <PropertyGroup Label="Globals"> | ||
| <__PyprojectClangCl_Props_Imported>true</__PyprojectClangCl_Props_Imported> | ||
| </PropertyGroup> | ||
| <PropertyGroup> | ||
| <!-- CLANG_PROFILE_PATH is configurable for "remote PGO builds" | ||
| For convenience, we also accept paths without trailing slashes. | ||
| --> | ||
| <CLANG_PROFILE_PATH Condition="'$(CLANG_PROFILE_PATH)' == ''">$(OutDir)</CLANG_PROFILE_PATH> | ||
| <_CLANG_PROFILE_PATH>$(CLANG_PROFILE_PATH)</_CLANG_PROFILE_PATH> | ||
| <_CLANG_PROFILE_PATH Condition="!HasTrailingSlash($(_CLANG_PROFILE_PATH))">$(_CLANG_PROFILE_PATH)\</_CLANG_PROFILE_PATH> | ||
| </PropertyGroup> | ||
| <ItemGroup> | ||
| <_profrawFiles Include="$(OutDir)instrumented\$(TargetName)_*.profraw" /> | ||
| </ItemGroup> | ||
| <Target Name="EnsureClangProfileData" BeforeTargets="PrepareForBuild" | ||
| Condition="'$(SupportPGO)' and $(Configuration) == 'PGUpdate'"> | ||
| <Error Text="PGO run did not succeed (no $(TargetName)_*.profraw files) and there is no data to merge" | ||
| Condition="$(RequireProfileData) == 'true' and @(_profrawFiles) == ''" /> | ||
| </Target> | ||
| <Target Name="MergeClangProfileData" BeforeTargets="PrepareForBuild" | ||
| Condition="'$(SupportPGO)' and $(Configuration) == 'PGUpdate'" | ||
| Inputs="@(_profrawFiles)" | ||
| Outputs="$(OutDir)instrumented\profdata.profdata"> | ||
| <Exec | ||
| Command='"$(LLVMInstallDir)\bin\llvm-profdata.exe" merge -output="$(OutDir)instrumented\profdata.profdata" "$(OutDir)instrumented\*_*.profraw"' /> | ||
| </Target> | ||
| <Target Name="CleanClangProfileData" BeforeTargets="Clean"> | ||
| <Delete Files="@(_profrawFiles)" TreatErrorsAsWarnings="true" /> | ||
| <Delete Files="$(OutDir)instrumented\profdata.profdata" TreatErrorsAsWarnings="true" /> | ||
| </Target> | ||
| <ItemDefinitionGroup> | ||
| <ClCompile> | ||
| <AdditionalOptions>-Wno-deprecated-non-prototype -Wno-unused-label -Wno-pointer-sign -Wno-incompatible-pointer-types-discards-qualifiers -Wno-unused-function %(AdditionalOptions)</AdditionalOptions> | ||
| <AdditionalOptions Condition="$(Configuration) != 'Debug'">-flto=thin %(AdditionalOptions)</AdditionalOptions> | ||
| <AdditionalOptions Condition="$(SupportPGO) and $(Configuration) == 'PGInstrument'">-fprofile-instr-generate=$(_CLANG_PROFILE_PATH)$(TargetName)_%m.profraw %(AdditionalOptions)</AdditionalOptions> | ||
| <AdditionalOptions Condition="$(SupportPGO) and $(Configuration) == 'PGUpdate'">-fprofile-instr-use=$(OutDir)instrumented\profdata.profdata -Wno-profile-instr-unprofiled %(AdditionalOptions)</AdditionalOptions> | ||
| </ClCompile> | ||
| </ItemDefinitionGroup> | ||
| </Project> |
Uh oh!
There was an error while loading. Please reload this page.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Interestingly, for debug builds I now need this, too. Never needed before, see #130040 (comment). Will anyway come with that PR...