On Apr 7, 2025, at 13:15, Mark Millard <mark...@yahoo.com> wrote:
> On Apr 7, 2025, at 10:15, Mark Millard <mark...@yahoo.com> wrote:
>
>> On Apr 7, 2025, at 09:44, Mark Millard <mark...@yahoo.com> wrote:
>>
>>> On Apr 7, 2025, at 08:14, Baptiste Daroussin <b...@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
