8000 GH-130090: build time analysis by chris-eibl · Pull Request #131005 · python/cpython · GitHub
[go: up one dir, main page]

Skip to content

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

Closed
wants to merge 22 commits into from
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
22 commits
Select commit Hold shift + click to select a range
859c89f
minimal changes needed for PGO with clang-cl
chris-eibl Feb 9, 2025
a529c39
like for MSVC, don't use link time optimization
chris-eibl Feb 9, 2025
26fb51f
Do not build _freeze_module twice in case of PGO
chris-eibl Feb 9, 2025
6e2cb69
remove /arch:AVX for blake2module.c again
chris-eibl Feb 10, 2025
7b46aeb
Revert "Do not build _freeze_module twice in case of PGO"
chris-eibl Feb 10, 2025
ced66bd
always clean the profile directory when doing a new clang PGO build
chris-eibl Feb 10, 2025
1aae65d
Merge remote-tracking branch 'origin/main' into clang-pgo
chris-eibl Feb 11, 2025
52fd5ab
Merge branch 'main' into clang-pgo
chris-eibl Feb 13, 2025
c2ecb57
blurb it
chris-eibl Feb 13, 2025
ad72df5
Adding myself to ACKS
chris-eibl Feb 13, 2025
74ec74e
extract pyproject-clangcl.props
chris-eibl Feb 13, 2025
79ce418
Merge branch 'python:main' into clang-pgo
chris-eibl Feb 16, 2025
8c8aa79
move MergeClangProfileData to pyproject-clangcl.props
chris-eibl Feb 16, 2025
2a9da27
rename RequirePGCFiles to RequireProfileData
chris-eibl Feb 16, 2025
ea4de96
Apply suggestions from code review
chris-eibl Feb 18, 2025
3346b9d
Use -Wno-profile-instr-unprofiled in the PGUpdate case
chris-eibl Feb 18, 2025
9db1a29
introduce CLANG_PROFILE_PATH
chris-eibl Feb 19, 2025
0e6f95f
add build time analysis
chris-eibl Mar 9, 2025
0bd337d
Interestingly, for debug builds I now need this, too.
chris-eibl Mar 9, 2025
981210b
fix for older clangs
chris-eibl Mar 9, 2025
e1dfc39
use -flto=thin
chris-eibl Mar 9, 2025
9879c49
remove debug print
chris-eibl Mar 9, 2025
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion Include/internal/pycore_debug_offsets.h
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@ extern "C" {
declaration \
_GENERATE_DEBUG_SECTION_LINUX(name)

#if defined(MS_WINDOWS)
#if defined(MS_WINDOWS)&& !defined(__clang__)
Copy link
Member Author

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...

#define _GENERATE_DEBUG_SECTION_WINDOWS(name) \
_Pragma(Py_STRINGIFY(section(Py_STRINGIFY(name), read, write))) \
__declspec(allocate(Py_STRINGIFY(name)))
Expand Down
1 change: 1 addition & 0 deletions Misc/ACKS
Original file line number Diff line number Diff line change
Expand Up @@ -504,6 +504,7 @@ Grant Edwards
Vlad Efanov
Zvi Effron
John Ehresman
Chris Eibl
Tal Einat
Eric Eisner
Andrew Eland
Expand Down
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.
1 change: 1 addition & 0 deletions PCbuild/_freeze_module.vcxproj
Original file line number Diff line number Diff line change
Expand Up @@ -92,6 +92,7 @@
<AdditionalIncludeDirectories>$(IntDir);%(AdditionalIncludeDirectories)</AdditionalIncludeDirectories>
<Optimization>Disabled</Optimization>
<WholeProgramOptimization>false</WholeProgramOptimization>
<AdditionalOptions Condition="$(PlatformToolset) == 'ClangCL'">%(AdditionalOptions) -fno-lto</AdditionalOptions>
</ClCompile>
<Link>
<SubSystem>Console</SubSystem>
Expand Down
263 changes: 263 additions & 0 deletions PCbuild/analyse_build_times.py
6D47
Original file line number Diff line number Diff line change
@@ -0,0 +1,263 @@
import argparse
Copy link
Member Author

Choose a reason for hiding this comment

The 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"
Copy link
Member Author

Choose a reason for hiding this comment

The 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)
48 changes: 48 additions & 0 deletions PCbuild/pyproject-clangcl.props
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>
Loading
0