Date: Tue, 8 Apr 2025 01:06:09 -0700 From: Mark Millard <marklmi@yahoo.com> To: Baptiste Daroussin <bapt@FreeBSD.org> Cc: Gleb Popov <6yearold@gmail.com>, FreeBSD Current <freebsd-current@freebsd.org>, FreeBSD Mailing List <freebsd-ports@freebsd.org> Subject: Re: UPDATE: pkg 2.1.0 looks to be making official bulk builds of packages take much longer [a specific package with large time factor] Message-ID: <D391C802-FBE8-4AFC-818F-93A5FF9EF3A1@yahoo.com> In-Reply-To: <178AD8CD-57F2-4ADB-AE82-6B0C7A4D2C01@yahoo.com> References: <8E2FBAD3-EF6F-4D99-A340-21F8FD19AE0F@yahoo.com> <FA9C7841-6D61-4285-AC6D-46328CBC56D2@yahoo.com> <C7BBEC76-228F-4F9E-A5F9-86E9F53372FD@yahoo.com> <D3C2F75D-838B-47E9-B125-71104A3C16EA@yahoo.com> <CD66A7B2-422B-40FE-BB17-145032DBA46F@FreeBSD.org> <84FBBAF8-025E-4B9D-9797-51735567A8DB@yahoo.com> <B295D1CB-E47D-4359-A79A-986213E7AFCE@yahoo.com> <366E27FD-FA5B-4BF8-B6C4-6C495DB289C5@yahoo.com> <CALH631mm8cdL1A9TaumnENk9OGCm=PEfMDH6uSvjKaUDuzg8Hw@mail.gmail.com> <F82E31E6-D9C1-461A-B3C8-4DB5D491C000@yahoo.com> <7ziazrj7szuqhov3oppjbh3jyu3f2p2owntv4oxprelrdjzc6u@hkuf5szf3zwy> <0414EBFB-B63A-4738-ADB0-38B6CF3725DA@yahoo.com> <05128806-8F20-43A6-946B-A3780259F61A@yahoo.com> <178AD8CD-57F2-4ADB-AE82-6B0C7A4D2C01@yahoo.com>
index | next in thread | previous in thread | raw e-mail
On Apr 7, 2025, at 13:15, Mark Millard <marklmi@yahoo.com> wrote:
> On Apr 7, 2025, at 10:15, Mark Millard <marklmi@yahoo.com> wrote:
>
>> On Apr 7, 2025, at 09:44, Mark Millard <marklmi@yahoo.com> wrote:
>>
>>> On Apr 7, 2025, at 08:14, Baptiste Daroussin <bapt@FreeBSD.org> wrote:
>>>
>>>> On Mon 07 Apr 08:07, Mark Millard wrote:
>>>>> . . .
>>>>
>>>> Listing like this is clearly not any useful, the problem we have is the
>>>> performance changes depending on what is happening in parallel on the machines.
>>>
>>> I've been exploring looking for an example that reproduces the
>>> timing issue via commands like:
>>>
>>> # poudriere bulk -jrelease-aarch64 -v -p default -c www/gitlab@ee
>>> vs.
>>> # poudriere bulk -jrelease-aarch64 -v -p alt -c www/gitlab@ee
>>>
>>> so that prior builds are not involved in creating such a context.
>>> Also, when www/gitlab@ee itself is building, no other builder will
>>> be active.
>>>
>>> I've started such a build based on a pkg 2.0.6 /usr/ports/ context
>>> and will try one based on a pkg 2.1.0 /usr/ports-alt/ context.
>>>
>>> I'm trying www/gitlab@ee because, on beefy17, it went from:
>>>
>>> 00:09:01 (pre pkg 2.1.0 example)
>>
>> I must have clicked on the wrong thing for the above. Looking again:
>>
>> build of www/gitlab@ee | gitlab-ee-17.10.0 ended at Wed Mar 26 10:27:22 UTC 2025
>> build time: 00:13:50
>>
>>> to:
>>> 05:35:01 (pkg 23.1.0 example)
>>>
>>> (so somewhat over 37 times longer)
>
> Make that "somewhat over 24 times".
>
>>> and when I looked it up
>>> it has a huge number of dependencies:
>>>
>>> # pkg rquery -U -r FreeBSD "%#d : %n %o" www/gitlab@ee
>>> 298 : gitlab-ee www/gitlab
>>>
>>> The factor of 37
>
> 24 instead
>
>>> is large enough to be unlikely to have only
>>> load averages on beefy17 as a major contributor.
>
> It is still unlikely that beefy17 had load averages
> of anywhere in the ballpark of 20 times the number
> of FreeBSD cpus.
>
>>> Given the
>>> evidence about the count of dependencies, I will see. what
>>> I get.
>>>
>>> The test environment is a Apple Silicon M4 MAX system with
>>> FreeBSD running under Parallels in macOS.
>>>
>>> [00:00:07] Building 943 packages using up to 14 builders
>>>
>>>
>>> OOPS (via checking ampere2 logs):
>>>
>>> Looks like aarch64 might end up blocked for a
>>> rubygem-redis-actionpack-rails70 "Phase: stage" failure. I
>>> may have to set up a amd64 context for such experiments.
>>
>> The above looks to be another example of looking at
>> that wrong thing.
>>
>> But, as I'm using 2 different vintages of ports tree,
>> there could be an issue for 1 even if there is not for
>> the other.
>>
>>>> which makes the performance issues invisible on local poudriere if you want to
>>>> test it on port A or port B, if we want to reduce the performance penalty we
>>>> need to be able to make a reproducible case which can then be profiled, to know
>>>> where to optimize if needed.
>>>>
>>>> I have tried to reproduce each individual case which happen in the ports tree
>>>> and I am not able to reproduce them, so impossible to know where to look at
>>>> exactly.
>>>
>>> I'm hoping to supply reproducible steps.
>>>
>>>> I know what is new and what causes the performance penalty, but not
>>>> which part is causing the super extra penalty on the cluster.
>>
>
> I'll note that both beefy17/18 and ampere2 get the
> time multipler effect. It it likely more noticable
> on ampere2 because ampere2 is likely a slower system
> generally.
>
> As for reproduction of the issue (in a much faster
> context), I also got more like about 26 sec in
> build-depends instead of about 12 sec. The overall
> time for building the 943 packages about about 10
> min longer.
>
> The pkg 2.0.6 vintage /usr/ports/ context got:
> (Note: There no "Allowing MAKE_JOBS for" notice for www/gitlab@ee .)
>
> [01:29:05] [01] [00:00:00] Building www/gitlab@ee | gitlab-ee-17.9.2_1
> [01:29:06] [01] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.9.2_1: check-sanity
> [01:29:06] [01] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.9.2_1: pkg-depends
> [01:29:06] [01] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.9.2_1: fetch-depends
> [01:29:06] [01] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.9.2_1: fetch
> [01:29:46] [01] [00:00:41] Status www/gitlab@ee | gitlab-ee-17.9.2_1: checksum
> [01:29:46] [01] [00:00:41] Status www/gitlab@ee | gitlab-ee-17.9.2_1: extract-depends
> [01:29:47] [01] [00:00:42] Status www/gitlab@ee | gitlab-ee-17.9.2_1: extract
> [01:29:56] [01] [00:00:51] Status www/gitlab@ee | gitlab-ee-17.9.2_1: patch-depends
> [01:29:56] [01] [00:00:51] Status www/gitlab@ee | gitlab-ee-17.9.2_1: patch
> [01:29:56] [01] [00:00:51] Status www/gitlab@ee | gitlab-ee-17.9.2_1: build-depends
> [01:30:08] [01] [00:01:03] Status www/gitlab@ee | gitlab-ee-17.9.2_1: lib-depends
> [01:30:08] [01] [00:01:03] Status www/gitlab@ee | gitlab-ee-17.9.2_1: configure
> [01:30:09] [01] [00:01:04] Status www/gitlab@ee | gitlab-ee-17.9.2_1: build
> [01:30:09] [01] [00:01:04] Status www/gitlab@ee | gitlab-ee-17.9.2_1: run-depends
> [01:30:09] [01] [00:01:04] Status www/gitlab@ee | gitlab-ee-17.9.2_1: stage
> [01:30:16] [01] [00:01:11] Status www/gitlab@ee | gitlab-ee-17.9.2_1: package
> [01:31:47] [01] [00:02:42] Finished www/gitlab@ee | gitlab-ee-17.9.2_1: Success
> . . .
> [01:31:50] [release-aarch64-default] [2025-04-07_09h06m32s] [committing] Time: 01:31:48
> Queued: 943 Inspected: 0 Ignored: 0 Built: 943 Failed: 0 Skipped: 0 Fetched: 0 Remaining: 0
> . . .
>
>
> The pkg 2.1.0 vintage /usr/ports-alt/ context:
> (Note: There was no "Allowing MAKE_JOBS for" notice for www/gitlab@ee .)
>
> [01:39:03] [01] [00:00:00] Building www/gitlab@ee | gitlab-ee-17.10.3
> [01:39:04] [01] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.10.3: check-sanity
> [01:39:04] [01] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.10.3: pkg-depends
> [01:39:04] [01] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.10.3: fetch-depends
> [01:39:04] [01] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.10.3: fetch
> [01:39:46] [01] [00:00:43] Status www/gitlab@ee | gitlab-ee-17.10.3: checksum
> [01:39:46] [01] [00:00:43] Status www/gitlab@ee | gitlab-ee-17.10.3: extract-depends
> [01:39:47] [01] [00:00:44] Status www/gitlab@ee | gitlab-ee-17.10.3: extract
> [01:39:57] [01] [00:00:54] Status www/gitlab@ee | gitlab-ee-17.10.3: patch-depends
> [01:39:57] [01] [00:00:54] Status www/gitlab@ee | gitlab-ee-17.10.3: patch
> [01:39:57] [01] [00:00:54] Status www/gitlab@ee | gitlab-ee-17.10.3: build-depends
> [01:40:23] [01] [00:01:20] Status www/gitlab@ee | gitlab-ee-17.10.3: lib-depends
> [01:40:23] [01] [00:01:20] Status www/gitlab@ee | gitlab-ee-17.10.3: configure
> [01:40:23] [01] [00:01:20] Status www/gitlab@ee | gitlab-ee-17.10.3: build
> [01:40:23] [01] [00:01:20] Status www/gitlab@ee | gitlab-ee-17.10.3: run-depends
> [01:40:24] [01] [00:01:21] Status www/gitlab@ee | gitlab-ee-17.10.3: stage
> [01:40:30] [01] [00:01:27] Status www/gitlab@ee | gitlab-ee-17.10.3: package
> [01:42:17] [01] [00:03:14] Finished www/gitlab@ee | gitlab-ee-17.10.3: Success
> . . .
> [01:42:20] [release-aarch64-alt] [2025-04-07_10h44m17s] [committing] Time: 01:42:08
> Queued: 943 Inspected: 0 Ignored: 0 Built: 943 Failed: 0 Skipped: 0 Fetched: 0 Remaining: 0
> . . .
>
>
> This sort of reminds me of an old issue I had on the PowerMac's
> back when I had access to working ones: poudriere had a contention
> issue with cpdup activity that made for long delays in the initial,
> parallel cpdup activity. I modified poudriere to stagger the
> activity in time to avoid it and cut the time greatly. (Not that
> such is known to be involved here.) Others did not necessarily see
> the same on other types of hardware. (I did not have access to a
> aarch64 or armv7 context at the time.)
I tried the www/gitlab@ee build step while using the boot media on
an older, 16-core Cortex-A72 system (a HoneyComb):
. . .
[00:02:04] [01] [00:00:00] Building www/gitlab@ee | gitlab-ee-17.10.3
[00:02:05] [01] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.10.3: check-sanity
[00:02:05] [01] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.10.3: pkg-depends
[00:02:05] [01] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.10.3: fetch-depends
[00:02:05] [01] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.10.3: fetch
[00:02:10] [01] [00:00:06] Status www/gitlab@ee | gitlab-ee-17.10.3: checksum
[00:02:11] [01] [00:00:07] Status www/gitlab@ee | gitlab-ee-17.10.3: extract-depends
[00:02:14] [01] [00:00:10] Status www/gitlab@ee | gitlab-ee-17.10.3: extract
[00:02:53] [01] [00:00:49] Status www/gitlab@ee | gitlab-ee-17.10.3: patch-depends
[00:02:53] [01] [00:00:49] Status www/gitlab@ee | gitlab-ee-17.10.3: patch
[00:02:53] [01] [00:00:49] Status www/gitlab@ee | gitlab-ee-17.10.3: build-depends
[00:04:54] [01] [00:02:50] Status www/gitlab@ee | gitlab-ee-17.10.3: lib-depends
[00:04:54] [01] [00:02:50] Status www/gitlab@ee | gitlab-ee-17.10.3: configure
[00:04:55] [01] [00:02:51] Status www/gitlab@ee | gitlab-ee-17.10.3: build
[00:04:55] [01] [00:02:51] Status www/gitlab@ee | gitlab-ee-17.10.3: run-depends
[00:04:58] [01] [00:02:54] Status www/gitlab@ee | gitlab-ee-17.10.3: stage
[00:05:46] [01] [00:03:42] Status www/gitlab@ee | gitlab-ee-17.10.3: package
[00:12:24] [01] [00:10:20] Finished www/gitlab@ee | gitlab-ee-17.10.3: Success
. . .
[00:12:35] [release-aarch64-alt] [2025-04-07_23h46m01s] [committing] Time: 00:12:29
Queued: 285 Inspected: 284 Ignored: 0 Built: 1 Failed: 0 Skipped: 0 Fetched: 0 Remaining: 0
. . .
So: about 2 min for build-depends and 6+ min for package.
===
Mark Millard
marklmi at yahoo.com
home |
help
Want to link to this message? Use this
URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?D391C802-FBE8-4AFC-818F-93A5FF9EF3A1>