diff --git a/Project.toml b/Project.toml index 21e6a2db..fc49d791 100644 --- a/Project.toml +++ b/Project.toml @@ -1,7 +1,7 @@ name = "BinaryBuilder" uuid = "12aac903-9f7c-5d81-afc2-d9565ea332ae" -authors = ["Elliot Saba "] version = "0.6.5" +authors = ["Elliot Saba "] [deps] ArgParse = "c7e460c6-2fb9-53a9-8c5b-16f535851c63" @@ -29,6 +29,7 @@ SHA = "ea8e919c-243c-51af-8825-aaa63cd721ce" Scratch = "6c6a2e73-6563-6170-7368-637461726353" Sockets = "6462fe0b-24de-5631-8697-dd941f90decc" TOML = "fa267f1f-6049-4f14-aa54-33bafae1ed76" +TimerOutputs = "a759f4b9-e2f1-59dc-863e-4aeb61b1ea8f" UUIDs = "cf7118a7-6976-5b1a-9a39-7adc72f591a4" ghr_jll = "07c12ed4-43bc-5495-8a2a-d5838ef8d533" @@ -51,6 +52,7 @@ RegistryTools = "2.1" SHA = "0.7, 1" Scratch = "1.0" TOML = "1" +TimerOutputs = "0.5" ghr_jll = "0.13, 0.14, 0.17" julia = "1.7" diff --git a/azure-pipelines.yml b/azure-pipelines.yml index fecb42dd..fe1e15b7 100644 --- a/azure-pipelines.yml +++ b/azure-pipelines.yml @@ -42,6 +42,7 @@ jobs: - bash: | set -e $(JULIA) -e 'using Pkg; Pkg.Registry.update(); Pkg.instantiate()' + $(JULIA) -e 'using Pkg; Pkg.add(name="BinaryBuilderBase", rev="ib/timeroutputs")' $(JULIA) -e 'using BinaryBuilder; BinaryBuilder.versioninfo()' $(JULIA) -e 'using Pkg; Pkg.status(; mode=PKGMODE_MANIFEST)' name: SystemInfo @@ -66,7 +67,7 @@ jobs: - bash: | set -e $(JULIA) -e 'using Pkg; Pkg.gc()' - $(JULIA) --check-bounds=yes --inline=yes -e 'using Pkg; Pkg.Registry.update(); Pkg.instantiate(); Pkg.test(coverage=true)' + $(JULIA) --check-bounds=yes --inline=yes -e 'using Pkg; Pkg.Registry.update(); Pkg.add(name="BinaryBuilderBase", rev="ib/timeroutputs"); Pkg.instantiate(); Pkg.test(coverage=true)' $(JULIA) -e 'using Pkg; Pkg.add("Coverage"); using Coverage; Codecov.submit(process_folder())' || true name: Test diff --git a/src/Auditor.jl b/src/Auditor.jl index d5b66aed..a183b60c 100644 --- a/src/Auditor.jl +++ b/src/Auditor.jl @@ -5,10 +5,18 @@ using Base.BinaryPlatforms using Pkg using ObjectFile -using BinaryBuilderBase: march +using BinaryBuilderBase: march, BBB_TIMER, merge_bbb_timer! +using TimerOutputs: TimerOutput, @timeit, reset_timer! export audit, collect_files, collapse_symlinks +""" + current_timer_path(to::TimerOutput) + +Get the current tree path as a vector of section names from the timer's stack. +""" +current_timer_path(to::TimerOutput) = [t.name for t in to.timer_stack] + # Some functions need to run commands in sandboxes mounted on the same prefix and we # can't allow them to clash, otherwise one may be unmounting the filesystem while # another is still operating. @@ -22,6 +30,37 @@ const AUDITOR_LOGGING_LOCK = ReentrantLock() const PATCHELF_FILE_LOCKS = Dict{String,ReentrantLock}() const PATCHELF_FILE_LOCKS_LOCK = ReentrantLock() +# Collect thread-local timers for merging +const THREAD_TIMERS = Set{TimerOutput}() +const THREAD_TIMERS_LOCK = ReentrantLock() + +""" + get_thread_timer() + +Get or create a thread-local TimerOutput, registering it for later merging. +""" +function get_thread_timer() + get!(task_local_storage(), :auditor_timer) do + timer = TimerOutput() + Base.@lock THREAD_TIMERS_LOCK push!(THREAD_TIMERS, timer) + timer + end::TimerOutput +end + +""" + merge_thread_timers!(tree_point::Vector{String}) + +Merge all thread-local timers into BBB_TIMER at the given tree_point and reset them. +""" +function merge_thread_timers!(tree_point::Vector{String}) + Base.@lock THREAD_TIMERS_LOCK begin + for timer in THREAD_TIMERS + merge_bbb_timer!(timer; tree_point) + reset_timer!(timer) + end + end +end + """ with_patchelf_lock(f, path::AbstractString) @@ -31,16 +70,22 @@ This prevents concurrent patchelf operations on the same file. function with_patchelf_lock(f, path::AbstractString) # Normalize the path to ensure consistent locking path = realpath(path) - + filename = basename(path) + # Get or create the lock for this file file_lock = Base.@lock PATCHELF_FILE_LOCKS_LOCK begin get!(PATCHELF_FILE_LOCKS, path) do ReentrantLock() end end - - # Execute with the file-specific lock held - Base.@lock file_lock f() + + # Execute with the file-specific lock held, timing both the lock wait and the inner operation + timer = get_thread_timer() + @timeit timer "patchelf $(filename) (incl. lock)" begin + Base.@lock file_lock begin + @timeit timer "patchelf $(filename)" f() + end + end end # Helper function to run a command and print to `io` its invocation and full @@ -102,6 +147,9 @@ function audit(prefix::Prefix, src_name::AbstractString = ""; has_csl::Bool = true, require_license::Bool = true, ) + # Capture the current timer tree path for merging thread-local timers later + timer_tree_point = current_timer_path(BBB_TIMER) + # This would be really weird, but don't let someone set `silent` and `verbose` to true if silent verbose = false @@ -148,7 +196,7 @@ function audit(prefix::Prefix, src_name::AbstractString = ""; # for Windows, for which however we have to set autofix=false: # https://github.com/JuliaPackaging/Yggdrasil/pull/922. all_ok[] &= ensure_executability(oh; verbose, silent) - + # If this is a dynamic object, do the dynamic checks if isdynamic(oh) # Check that the libgfortran version matches @@ -359,6 +407,10 @@ function audit(prefix::Prefix, src_name::AbstractString = ""; # Search for case-sensitive ambiguities all_ok[] &= check_case_sensitivity(prefix) + + # Merge thread-local timers back into the main timer + merge_thread_timers!(timer_tree_point) + return all_ok[] end diff --git a/src/AutoBuild.jl b/src/AutoBuild.jl index e749ca2c..5508415d 100644 --- a/src/AutoBuild.jl +++ b/src/AutoBuild.jl @@ -2,6 +2,8 @@ export build_tarballs, autobuild, build, get_meta_json import GitHub: gh_get_json, DEFAULT_API import SHA: sha256, sha1 using TOML, Dates, UUIDs +using TimerOutputs: @timeit, print_timer +using BinaryBuilderBase: BBB_TIMER, reset_bbb_timer! using RegistryTools import LibGit2 import PkgLicenses @@ -193,6 +195,8 @@ function build_tarballs(ARGS, src_name, src_version, sources, script, compression_format::String="gzip", kwargs...) @nospecialize + reset_bbb_timer!() + @timeit BBB_TIMER "build_tarballs" begin # See if someone has passed in `--help`, and if so, give them the # assistance they so clearly long for if "--help" in ARGS @@ -441,6 +445,9 @@ function build_tarballs(ARGS, src_name, src_version, sources, script, upload_to_github_releases(deploy_bin_repo, tag, products_dir; verbose=verbose) end + end # @timeit build_tarballs + print_timer(IOContext(stdout, :limit => false), BBB_TIMER; sortby=:firstexec) + println() return build_output_meta end @@ -515,7 +522,7 @@ function get_compilers_versions(; compilers = [:c]) return output end -function upload_to_github_releases(repo, tag, path; gh_auth=Wizard.github_auth(;allow_anonymous=false), +@timeit BBB_TIMER function upload_to_github_releases(repo, tag, path; gh_auth=Wizard.github_auth(;allow_anonymous=false), attempts::Int = 3, verbose::Bool = false) for attempt in 1:attempts try @@ -602,7 +609,7 @@ is_yggdrasil() = get(ENV, "YGGDRASIL", "false") == "true" # Use a Buildkite environment variable to get the current commit hash yggdrasil_head() = get(ENV, "BUILDKITE_COMMIT", "") -function register_jll(name, build_version, dependencies, julia_compat; +@timeit BBB_TIMER function register_jll(name, build_version, dependencies, julia_compat; deploy_repo="JuliaBinaryWrappers/$(namejll(name)).jl", code_dir=codedir(name), gh_auth=Wizard.github_auth(;allow_anonymous=false), @@ -800,7 +807,7 @@ here are the relevant actors, broken down in brief: * `compression_format`: the compression format used for the generated tarballs. """ -function autobuild(dir::AbstractString, +@timeit BBB_TIMER function autobuild(dir::AbstractString, src_name::AbstractString, src_version::VersionNumber, sources::Vector{<:AbstractSource}, @@ -836,13 +843,14 @@ function autobuild(dir::AbstractString, end # We must prepare our sources. Download them, hash them, etc... - source_files = download_source.(sources; verbose=verbose) + source_files = @timeit BBB_TIMER "Downloading sources" download_source.(sources; verbose=verbose) # Our build products will go into ./products out_path = joinpath(dir, "products") try mkpath(out_path) catch; end for platform in sort(collect(platforms), by = triplet) + @timeit BBB_TIMER "Building for $(triplet(platform))" begin timer = BuildTimer() timer.begin_setup = time() @@ -874,7 +882,7 @@ function autobuild(dir::AbstractString, target_artifact_paths = setup_deps(is_target_dependency, prefix, dependencies, concrete_platform, verbose) # Create a runner to work inside this workspace with the nonce built-in - ur = preferred_runner()( + ur = @timeit BBB_TIMER "Creating runner" preferred_runner()( prefix.path; cwd = "/workspace/srcdir", platform = concrete_platform, @@ -928,7 +936,7 @@ function autobuild(dir::AbstractString, """ dest_prefix = Prefix(BinaryBuilderBase.destdir(prefix.path, concrete_platform)) - did_succeed = with_logfile(dest_prefix, "$(src_name).log"; subdir=src_name) do io + did_succeed = @timeit BBB_TIMER "Running build script" with_logfile(dest_prefix, "$(src_name).log"; subdir=src_name) do io # Let's start the presentations with BinaryBuilder.jl write(io, "BinaryBuilder.jl version: $(get_bb_version())\n\n") # Get the list of compilers... @@ -959,6 +967,7 @@ function autobuild(dir::AbstractString, # Run an audit of the prefix to ensure it is properly relocatable timer.begin_audit = time() if !skip_audit + @timeit BBB_TIMER "Auditing build artifacts" begin audit_result = audit(dest_prefix, src_name; platform=platform, verbose=verbose, has_csl = any(getname.(dependencies) .== "CompilerSupportLibraries_jll"), @@ -971,10 +980,12 @@ function autobuild(dir::AbstractString, """, '\n' => ' ') error(strip(msg)) end + end # @timeit audit end timer.end_audit = time() # Finally, error out if something isn't satisfied + @timeit BBB_TIMER "Checking products" begin unsatisfied_so_die = false for p in products if platform isa AnyPlatform && !(p isa FileProduct) @@ -1009,8 +1020,10 @@ function autobuild(dir::AbstractString, ) end end + end # @timeit Checking products # Unsymlink all the deps from the dest_prefix + @timeit BBB_TIMER "Cleaning up" begin cleanup_dependencies(prefix, host_artifact_paths, default_host_platform) cleanup_dependencies(prefix, target_artifact_paths, concrete_platform) @@ -1029,6 +1042,7 @@ function autobuild(dir::AbstractString, # Compress log files compress_dir(logdir(dest_prefix; subdir=src_name); verbose) + end # @timeit Cleaning up # Once we're built up, go ahead and package this dest_prefix out timer.begin_package = time() @@ -1065,6 +1079,7 @@ function autobuild(dir::AbstractString, # Destroy the workspace, taking care to make sure that we don't run into any # permissions errors while we do so. + @timeit BBB_TIMER "Destroying workspace" begin Base.Filesystem.prepare_for_deletion(prefix.path) rm(prefix.path; recursive=true) @@ -1074,7 +1089,9 @@ function autobuild(dir::AbstractString, if isempty(readdir(build_path)) rm(build_path; recursive=true) end + end # @timeit Destroying workspace verbose && @info "$(timer)" + end # @timeit platform end # Return our product hashes @@ -1226,7 +1243,7 @@ function filter_main_tarball(tarball_filename, platform) end end -function rebuild_jll_package(name::String, build_version::VersionNumber, sources::Vector, +@timeit BBB_TIMER function rebuild_jll_package(name::String, build_version::VersionNumber, sources::Vector, platforms::Vector, products::Vector, dependencies::Vector, download_dir::String, upload_prefix::String; code_dir::String = codedir(name), @@ -1316,7 +1333,7 @@ function rebuild_jll_package(name::String, build_version::VersionNumber, sources kwargs...) end -function build_jll_package(src_name::String, +@timeit BBB_TIMER function build_jll_package(src_name::String, build_version::VersionNumber, sources::Vector, code_dir::String, @@ -1473,11 +1490,11 @@ function build_jll_package(src_name::String, libgfortran_version_mapping = BinaryPlatforms.libgfortran_version_mapping cxxstring_abi_mapping = BinaryPlatforms.cxxstring_abi_mapping libstdcxx_version_mapping = BinaryPlatforms.libstdcxx_version_mapping - + # Helper function to collapse dictionary of mappings down into a regex of # named capture groups joined by "|" operators c(mapping) = string("(",join(["(?<$k>$v)" for (k, v) in mapping], "|"), ")") - + # We're going to build a mondo regex here to parse everything: triplet_regex = Regex(string( "^", @@ -1494,7 +1511,7 @@ function build_jll_package(src_name::String, "(?(?:-[^-]+\\+[^-]+)*)?", "\$", )) - + m = match(triplet_regex, triplet) if m !== nothing # Helper function to find the single named field within the giant regex @@ -1517,7 +1534,7 @@ function build_jll_package(src_name::String, end end end - + # Extract the information we're interested in: arch = get_field(m, arch_mapping) os = get_field(m, os_mapping) @@ -1534,7 +1551,7 @@ function build_jll_package(src_name::String, return map(v -> Symbol(v[1]) => v[2], split.(tag_fields, "+")) end tags = split_tags(m["tags"]) - + # Special parsing of os version number, if any exists function extract_os_version(os_name, pattern) m_osvn = match(pattern, m[os_name]) @@ -1553,7 +1570,7 @@ function build_jll_package(src_name::String, if os == "openbsd" os_version = extract_os_version("openbsd", r".*openbsd([\d.]+)"sa) end - + return Platform( arch, os; validate_strict, @@ -1768,7 +1785,7 @@ function build_jll_package(src_name::String, end end -function push_jll_package(name, build_version; +@timeit BBB_TIMER function push_jll_package(name, build_version; code_dir = codedir(name), deploy_repo = "JuliaBinaryWrappers/$(namejll(name)).jl", gh_auth = Wizard.github_auth(;allow_anonymous=false))