On Apr 11, 2025, at 23:55, Mark Millard <mark...@yahoo.com> wrote: > On Apr 11, 2025, at 19:28, Mark Millard <mark...@yahoo.com> wrote: >> >>> . . . >>> >> . . . >> > > . . . > >> >> >> Back to the originally intended content . . . >> >> >> On Apr 11, 2025, at 14:04, Mark Millard <mark...@yahoo.com> wrote: >>> >>> On Apr 11, 2025, at 11:39, Mark Millard <mark...@yahoo.com> wrote: >>> >>>> On Apr 7, 2025, at 08:14, Baptiste Daroussin <b...@freebsd.org> wrote: >>>> >>>>> . . . >>>>> the problem we have is the >>>>> performance changes depending on what is happening in parallel on the >>>>> machines. >>>> >>>> In separate list messages I've provided multiple examples >>>> of the time-taking issue that do not depend on what is >>>> running in parallel on the machines, no parallel builds >>>> involved. >>>> >>>> Part of the issue is that there are thousands of examples of >>>> "small build-step time" packages for which the build-depends, >>>> lib-depends, run-depends combination, takes notable time, >>>> given that the total time contribution across those thousands >>>> of package builds is notable overall. >>>> >>>> As stands, mostly it is the early part of "bulk -c -a" avoids >>>> the issue via building packages that have no or few >>>> dependencies. Later "small build-step time" packages tend to >>>> have various dependencies, greatly changing the time scale >>>> for their builds. Few builds are of "large build-step >>>> time" packages (relative to there being 30000+ packages). That >>>> has implications for there being 30000+ packages to build for >>>> "bulk -c -a" or other builds with large numbers of packages >>>> to try to build. >>>> >>>>> which makes the performance issues invisible on local poudriere if you >>>>> want to >>>>> test it on port A or port B, >>>> >>>> I've provided counter examples to that that only involve the >>>> one builder, after the prerequisites have already been built >>>> (same or prior bulk run). >>>> >>>>> 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've provided examples of such . . . >>>> (time intervals shown are from the aarch64 >>>> Windows Dev Kit 2023 with just the one >>>> builder active) >>>> >>>> www/rt50 >>>> build-depends: 00:00:27->00:08:46 >> >> More detailed comparison/contrast of non-parallel builds: >> >> A pkg 2.0.6 vintage of ports tree on Windows Dev Kit 2023: >> >> [00:01:11] [01] [00:00:00] Building www/rt50 | rt50-5.0.7 >> [00:01:14] [01] [00:00:03] Status www/rt50 | rt50-5.0.7: check-sanity >> [00:01:14] [01] [00:00:03] Status www/rt50 | rt50-5.0.7: pkg-depends >> [00:01:15] [01] [00:00:04] Status www/rt50 | rt50-5.0.7: fetch-depends >> [00:01:15] [01] [00:00:04] Status www/rt50 | rt50-5.0.7: fetch >> [00:01:15] [01] [00:00:04] Status www/rt50 | rt50-5.0.7: checksum >> [00:01:15] [01] [00:00:04] Status www/rt50 | rt50-5.0.7: extract-depends >> [00:01:15] [01] [00:00:04] Status www/rt50 | rt50-5.0.7: extract >> [00:01:16] [01] [00:00:05] Status www/rt50 | rt50-5.0.7: patch-depends >> [00:01:16] [01] [00:00:05] Status www/rt50 | rt50-5.0.7: patch >> [00:01:16] [01] [00:00:05] Status www/rt50 | rt50-5.0.7: build-depends >> [00:01:24] [01] [00:00:13] Status www/rt50 | rt50-5.0.7: lib-depends >> [00:01:24] [01] [00:00:13] Status www/rt50 | rt50-5.0.7: configure >> [00:01:26] [01] [00:00:15] Status www/rt50 | rt50-5.0.7: build >> [00:01:26] [01] [00:00:15] Status www/rt50 | rt50-5.0.7: run-depends >> [00:01:26] [01] [00:00:15] Status www/rt50 | rt50-5.0.7: stage >> [00:01:29] [01] [00:00:18] Status www/rt50 | rt50-5.0.7: package >> [00:01:50] [01] [00:00:39] Finished www/rt50 | rt50-5.0.7: Success >> >> A pkg 2.1.0 vintage of ports tree on Windows Dev Kit 2023: >> >> [00:03:04] [06] [00:00:00] Building www/rt50 | rt50-5.0.7 >> [00:03:06] [06] [00:00:02] Status www/rt50 | rt50-5.0.7: check-sanity >> [00:03:06] [06] [00:00:02] Status www/rt50 | rt50-5.0.7: pkg-depends >> [00:03:07] [06] [00:00:03] Status www/rt50 | rt50-5.0.7: fetch-depends >> [00:03:07] [06] [00:00:03] Status www/rt50 | rt50-5.0.7: fetch >> [00:03:07] [06] [00:00:03] Status www/rt50 | rt50-5.0.7: checksum >> [00:03:07] [06] [00:00:03] Status www/rt50 | rt50-5.0.7: extract-depends >> [00:03:07] [06] [00:00:03] Status www/rt50 | rt50-5.0.7: extract >> [00:03:07] [06] [00:00:03] Status www/rt50 | rt50-5.0.7: patch-depends >> [00:03:08] [06] [00:00:04] Status www/rt50 | rt50-5.0.7: patch >> [00:03:08] [06] [00:00:04] Status www/rt50 | rt50-5.0.7: build-depends >> [00:16:26] [06] [00:13:22] Status www/rt50 | rt50-5.0.7: lib-depends >> [00:16:26] [06] [00:13:22] Status www/rt50 | rt50-5.0.7: configure >> [00:16:27] [06] [00:13:23] Status www/rt50 | rt50-5.0.7: build >> [00:16:27] [06] [00:13:23] Status www/rt50 | rt50-5.0.7: run-depends >> [00:16:28] [06] [00:13:24] Status www/rt50 | rt50-5.0.7: stage >> [00:16:30] [06] [00:13:26] Status www/rt50 | rt50-5.0.7: package >> [00:17:03] [06] [00:13:59] Finished www/rt50 | rt50-5.0.7: Success >> >> (That I got the 00:13:22 is interesting, given the prior >> 00:08:46. May be the A78C cores were used instead of the >> X1C cores? May be that there were no builds, just Inspecting >> activity for the prerequisites. Did I not match the USE_TMPFS >> settings? I expect that the general structural conclusions >> are not invalidated.) >> >>>> devel/py-inline-snapshot@py311 >>>> build-depends: 00:00:01->00:00:55 >>>> run-depends: 00:00:56->00:01:47 >> >> A pkg 2.0.6 vintage of ports tree on Windows Dev Kit 2023: >> >> [00:00:54] [04] [00:00:00] Building devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1 >> [00:00:54] [04] [00:00:00] Allowing MAKE_JOBS for >> devel/py-inline-snapshot@py311 | py311-inline-snapshot-0.18.1 >> [00:00:59] [04] [00:00:05] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: check-sanity >> [00:00:59] [04] [00:00:05] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: pkg-depends >> [00:00:59] [04] [00:00:05] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: fetch-depends >> [00:00:59] [04] [00:00:05] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: fetch >> [00:01:00] [04] [00:00:06] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: checksum >> [00:01:00] [04] [00:00:06] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: extract-depends >> [00:01:00] [04] [00:00:06] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: extract >> [00:01:00] [04] [00:00:06] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: patch-depends >> [00:01:00] [04] [00:00:06] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: patch >> [00:01:00] [04] [00:00:06] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: build-depends >> [00:01:01] [04] [00:00:07] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: lib-depends >> [00:01:01] [04] [00:00:07] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: configure >> [00:01:01] [04] [00:00:07] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: build >> [00:01:02] [04] [00:00:08] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: run-depends >> [00:01:03] [04] [00:00:09] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: stage >> [00:01:03] [04] [00:00:09] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: package >> [00:01:04] [04] [00:00:10] Finished devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.18.1: Success >> >> A pkg 2.1.0 vintage of ports tree on Windows Dev Kit 2023: >> >> [00:02:46] [02] [00:00:00] Building devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8 >> [00:02:46] [02] [00:00:00] Allowing MAKE_JOBS for >> devel/py-inline-snapshot@py311 | py311-inline-snapshot-0.20.8 >> [00:02:47] [02] [00:00:01] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: check-sanity >> [00:02:47] [02] [00:00:01] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: pkg-depends >> [00:02:47] [02] [00:00:01] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: fetch-depends >> [00:02:47] [02] [00:00:01] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: fetch >> [00:02:47] [02] [00:00:01] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: checksum >> [00:02:47] [02] [00:00:01] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: extract-depends >> [00:02:47] [02] [00:00:01] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: extract >> [00:02:47] [02] [00:00:01] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: patch-depends >> [00:02:47] [02] [00:00:01] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: patch >> [00:02:48] [02] [00:00:02] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: build-depends >> [00:03:59] [02] [00:01:13] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: lib-depends >> [00:03:59] [02] [00:01:13] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: configure >> [00:03:59] [02] [00:01:13] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: build >> [00:04:00] [02] [00:01:14] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: run-depends >> [00:05:27] [02] [00:02:41] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: stage >> [00:05:28] [02] [00:02:42] Status devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: package >> [00:05:28] [02] [00:02:42] Finished devel/py-inline-snapshot@py311 | >> py311-inline-snapshot-0.20.8: Success >> >> (Again longer 2.1.0 times vs. previous 2.1.0 times.) >> >>>> >>>> mail/mailest@nox >>>> build-depends: 00:00:01->00:00:28 >>>> run-depends: 00:00:30->00:00:59 >> >> A pkg 2.0.6 vintage of ports tree on Windows Dev Kit 2023: >> >> [00:00:58] [01] [00:00:00] Building mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21 >> [00:00:59] [01] [00:00:01] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: check-sanity >> [00:00:59] [01] [00:00:01] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: pkg-depends >> [00:00:59] [01] [00:00:01] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: fetch-depends >> [00:00:59] [01] [00:00:01] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: fetch >> [00:00:59] [01] [00:00:01] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: checksum >> [00:01:00] [01] [00:00:02] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: extract-depends >> [00:01:00] [01] [00:00:02] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: extract >> [00:01:00] [01] [00:00:02] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: patch-depends >> [00:01:00] [01] [00:00:02] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: patch >> [00:01:00] [01] [00:00:02] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: build-depends >> [00:01:00] [01] [00:00:02] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: lib-depends >> [00:01:00] [01] [00:00:02] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: configure >> [00:01:00] [01] [00:00:02] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: build >> [00:01:03] [01] [00:00:05] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: run-depends >> [00:01:08] [01] [00:00:10] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: stage >> [00:01:09] [01] [00:00:11] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: package >> [00:01:09] [01] [00:00:11] Finished mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: Success >> >> A pkg 2.1.0 vintage of ports tree on Windows Dev Kit 2023: >> >> [00:02:50] [01] [00:00:00] Building mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21 >> [00:02:51] [01] [00:00:01] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: check-sanity >> [00:02:51] [01] [00:00:01] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: pkg-depends >> [00:02:51] [01] [00:00:01] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: fetch-depends >> [00:02:51] [01] [00:00:01] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: fetch >> [00:02:51] [01] [00:00:01] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: checksum >> [00:02:51] [01] [00:00:01] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: extract-depends >> [00:02:51] [01] [00:00:01] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: extract >> [00:02:51] [01] [00:00:01] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: patch-depends >> [00:02:51] [01] [00:00:01] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: patch >> [00:02:52] [01] [00:00:02] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: build-depends >> [00:02:52] [01] [00:00:02] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: lib-depends >> [00:03:31] [01] [00:00:41] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: configure >> [00:03:31] [01] [00:00:41] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: build >> [00:03:32] [01] [00:00:42] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: run-depends >> [00:04:08] [01] [00:01:18] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: stage >> [00:04:08] [01] [00:01:18] Status mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: package >> [00:04:09] [01] [00:01:19] Finished mail/mailest@nox | >> mailest-emacs_nox-0.9.24_21: Success >> >> (Again longer 2.1.0 times vs. previous 2.1.0 times.) >> >>>> >>>> devel/dwarves >>>> build-depends: 00:00:05->00:02:23 >>>> lib-depends: 00:02:23->00:02:42 >> >> A pkg 2.0.6 vintage of ports tree on Windows Dev Kit 2023: >> >> [00:00:56] [07] [00:00:00] Building devel/dwarves | dwarves-1.19_3 >> [00:01:01] [07] [00:00:05] Status devel/dwarves | dwarves-1.19_3: >> check-sanity >> [00:01:01] [07] [00:00:05] Status devel/dwarves | dwarves-1.19_3: >> pkg-depends >> [00:01:01] [07] [00:00:05] Status devel/dwarves | dwarves-1.19_3: >> fetch-depends >> [00:01:01] [07] [00:00:05] Status devel/dwarves | dwarves-1.19_3: fetch >> [00:01:01] [07] [00:00:05] Status devel/dwarves | dwarves-1.19_3: >> checksum >> [00:01:01] [07] [00:00:05] Status devel/dwarves | dwarves-1.19_3: >> extract-depends >> [00:01:01] [07] [00:00:05] Status devel/dwarves | dwarves-1.19_3: extract >> [00:01:02] [07] [00:00:06] Status devel/dwarves | dwarves-1.19_3: >> patch-depends >> [00:01:02] [07] [00:00:06] Status devel/dwarves | dwarves-1.19_3: patch >> [00:01:02] [07] [00:00:06] Status devel/dwarves | dwarves-1.19_3: >> build-depends >> [00:01:07] [07] [00:00:11] Status devel/dwarves | dwarves-1.19_3: >> lib-depends >> [00:01:08] [07] [00:00:12] Status devel/dwarves | dwarves-1.19_3: >> configure >> [00:01:08] [07] [00:00:12] Status devel/dwarves | dwarves-1.19_3: build >> [00:01:13] [07] [00:00:17] Status devel/dwarves | dwarves-1.19_3: >> run-depends >> [00:01:13] [07] [00:00:17] Status devel/dwarves | dwarves-1.19_3: stage >> [00:01:13] [07] [00:00:17] Status devel/dwarves | dwarves-1.19_3: package >> [00:01:14] [07] [00:00:18] Finished devel/dwarves | dwarves-1.19_3: Success >> >> A pkg 2.1.0 vintage of ports tree on Windows Dev Kit 2023: >> >> [00:02:54] [05] [00:00:00] Building devel/dwarves | dwarves-1.19_3 >> [00:02:58] [05] [00:00:04] Status devel/dwarves | dwarves-1.19_3: >> check-sanity >> [00:02:58] [05] [00:00:04] Status devel/dwarves | dwarves-1.19_3: >> pkg-depends >> [00:02:59] [05] [00:00:05] Status devel/dwarves | dwarves-1.19_3: >> fetch-depends >> [00:02:59] [05] [00:00:05] Status devel/dwarves | dwarves-1.19_3: fetch >> [00:02:59] [05] [00:00:05] Status devel/dwarves | dwarves-1.19_3: >> checksum >> [00:02:59] [05] [00:00:05] Status devel/dwarves | dwarves-1.19_3: >> extract-depends >> [00:02:59] [05] [00:00:05] Status devel/dwarves | dwarves-1.19_3: extract >> [00:02:59] [05] [00:00:05] Status devel/dwarves | dwarves-1.19_3: >> patch-depends >> [00:02:59] [05] [00:00:05] Status devel/dwarves | dwarves-1.19_3: patch >> [00:02:59] [05] [00:00:05] Status devel/dwarves | dwarves-1.19_3: >> build-depends >> [00:05:33] [05] [00:02:39] Status devel/dwarves | dwarves-1.19_3: >> lib-depends >> [00:06:07] [05] [00:03:13] Status devel/dwarves | dwarves-1.19_3: >> configure >> [00:06:07] [05] [00:03:13] Status devel/dwarves | dwarves-1.19_3: build >> [00:06:12] [05] [00:03:18] Status devel/dwarves | dwarves-1.19_3: >> run-depends >> [00:06:12] [05] [00:03:18] Status devel/dwarves | dwarves-1.19_3: stage >> [00:06:12] [05] [00:03:18] Status devel/dwarves | dwarves-1.19_3: package >> [00:06:12] [05] [00:03:18] Finished devel/dwarves | dwarves-1.19_3: Success >> >> (Again longer 2.1.0 times vs. previous 2.1.0 times.) >> >>> net-mgmt/fastnetmon >>> build-depends: 00:00:03->00:00:42 >>> lib-depends: 00:00:42->00:01:29 >> >> A pkg 2.0.6 vintage of ports tree on Windows Dev Kit 2023: >> >> [00:01:00] [02] [00:00:00] Building net-mgmt/fastnetmon | fastnetmon-1.2.8 >> [00:01:00] [02] [00:00:00] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: check-sanity >> [00:01:00] [02] [00:00:00] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: pkg-depends >> [00:01:01] [02] [00:00:01] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: fetch-depends >> [00:01:01] [02] [00:00:01] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: fetch >> [00:01:01] [02] [00:00:01] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: checksum >> [00:01:01] [02] [00:00:01] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: extract-depends >> [00:01:01] [02] [00:00:01] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: extract >> [00:01:01] [02] [00:00:01] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: patch-depends >> [00:01:01] [02] [00:00:01] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: patch >> [00:01:01] [02] [00:00:01] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: build-depends >> [00:01:03] [02] [00:00:03] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: lib-depends >> [00:01:07] [02] [00:00:07] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: configure >> [00:01:10] [02] [00:00:10] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: build >> [00:03:15] [02] [00:02:15] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: run-depends >> [00:03:15] [02] [00:02:15] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: stage >> [00:03:15] [02] [00:02:15] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: package >> [00:03:18] [02] [00:02:18] Finished net-mgmt/fastnetmon | >> fastnetmon-1.2.8: Success >> >> A pkg 2.1.0 vintage of ports tree on Windows Dev Kit 2023: >> >> [00:02:54] [06] [00:00:00] Building net-mgmt/fastnetmon | fastnetmon-1.2.8 >> [00:02:55] [06] [00:00:01] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: check-sanity >> [00:02:55] [06] [00:00:01] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: pkg-depends >> [00:02:56] [06] [00:00:02] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: fetch-depends >> [00:02:56] [06] [00:00:02] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: fetch >> [00:02:56] [06] [00:00:02] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: checksum >> [00:02:56] [06] [00:00:02] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: extract-depends >> [00:02:56] [06] [00:00:02] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: extract >> [00:02:56] [06] [00:00:02] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: patch-depends >> [00:02:56] [06] [00:00:02] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: patch >> [00:02:56] [06] [00:00:02] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: build-depends >> [00:04:10] [06] [00:01:16] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: lib-depends >> [00:05:41] [06] [00:02:47] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: configure >> [00:05:44] [06] [00:02:50] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: build >> [00:07:43] [06] [00:04:49] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: run-depends >> [00:07:43] [06] [00:04:49] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: stage >> [00:07:44] [06] [00:04:50] Status net-mgmt/fastnetmon | >> fastnetmon-1.2.8: package >> [00:07:46] [06] [00:04:52] Finished net-mgmt/fastnetmon | >> fastnetmon-1.2.8: Success >> >> (Again longer 2.1.0 times vs. previous 2.1.0 times.) >> >>> (See later below.) >>> >>>> The timings are from the column next to >>>> the Building/Status/Finished column from >>>> using bulk -v , not from the column for >>>> the overall bulk run. >>>> >>>>> 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. >>>> >>>> Try some of the examples that I've provided? >>>> >>>> There are more examples that I could check >>>> and report non-parallel timings on if you >>>> want. I just picked to report on only a few >>>> initially. >>>> >>>> An example that you might want is my >>>> providing more examples of lib-depends >>>> with non-parallel timings. >>> >>> I took a quick look and quickly ran into: >>> (aarch64 Windows Dev Kit 2023 no-parallel-builders >>> timing again, after having built the prerequisites >>> that had not previously been built) >>> >>> [00:11:37] [01] [00:00:00] Building net-mgmt/fastnetmon | fastnetmon-1.2.8 >>> [00:11:39] [01] [00:00:02] Status net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: check-sanity >>> [00:11:39] [01] [00:00:02] Status net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: pkg-depends >>> [00:11:40] [01] [00:00:03] Status net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: fetch-depends >>> [00:11:40] [01] [00:00:03] Status net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: fetch >>> [00:11:40] [01] [00:00:03] Status net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: checksum >>> [00:11:40] [01] [00:00:03] Status net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: extract-depends >>> [00:11:40] [01] [00:00:03] Status net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: extract >>> [00:11:40] [01] [00:00:03] Status net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: patch-depends >>> [00:11:40] [01] [00:00:03] Status net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: patch >>> [00:11:40] [01] [00:00:03] Status net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: build-depends >>> [00:12:19] [01] [00:00:42] Status net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: lib-depends >>> [00:13:06] [01] [00:01:29] Status net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: configure >>> [00:13:09] [01] [00:01:32] Status net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: build >>> [00:14:20] [01] [00:02:43] Status net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: run-depends >>> [00:14:20] [01] [00:02:43] Status net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: stage >>> [00:14:20] [01] [00:02:43] Status net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: package >>> [00:14:22] [01] [00:02:45] Finished net-mgmt/fastnetmon | >>> fastnetmon-1.2.8: Success >>> >>> (I still have thousands of packages that have not built >>> in the bulk -v -a build activity. The M4 MAX is in use >>> for that.) >>> >>>>> I know what is new and what causes the performance penalty, but not >>>>> which part is causing the super extra penalty on the cluster. >>>> >>>> Various examples reproduce the timing issues >>>> outside the cluster and without the parallel >>>> builds.
These results are from the M4 MAX context for pkg 2.1.0 use. I finished a "bulk -a" sequence (without having kldloaded linux support). So I can now do the likes of: # poudriere bulk -jrelease-aarch64 -v -p alt -C www/gitlab@ee without having to build the prerequisites. No parallel builds involved. For that specific example I'll do it once before rebooting and once after, checking on caching effects. FYI: [00:05:28] Building 285 packages using up to 12 builders (But the prerequisites just get: "Inspecting . . .: determining shlib requirements", no actual builds.) I'll not repeat that part below. I'll also note that "Creating pkg repository" after such a build seems to not be an incremental activity for the small number of packages that change (1 here): (before reboot case) [00:29:41] Creating pkg repository Creating repository in /tmp/packages: 100% Packing files for repository: 100% [01:34:32] Committing packages to repository: /usr/local/poudriere/data/packages/release-aarch64-alt/.real_1744660767 via .latest symlink (after reboot case) [00:28:08] Creating pkg repository Creating repository in /tmp/packages: 100% Packing files for repository: 100% [01:29:53] Committing packages to repository: /usr/local/poudriere/data/packages/release-aarch64-alt/.real_1744668230 via .latest symlink (I'm not so sure if the pkg-static threads for my context mostly end up waiting for each other, the "gstat -spod" L(q) generally showing 16..22, sometimes more. biord and getblk commonly show in top, with at most 1 CPU? showing.) The 1hr+ extra makes experimenting more time consuming. I'm glad it is the faster M4 MAX as the context. It also means that I'm unlikely to try such on the Windows Dev Kit 2023 where the time could be much longer. Before reboot (but after bulk -a): [00:05:44] [01] [00:00:00] Building www/gitlab@ee | gitlab-ee-17.10.3 [00:05:46] [01] [00:00:02] Status www/gitlab@ee | gitlab-ee-17.10.3: check-sanity [00:05:46] [01] [00:00:02] Status www/gitlab@ee | gitlab-ee-17.10.3: pkg-depends [00:05:46] [01] [00:00:02] Status www/gitlab@ee | gitlab-ee-17.10.3: fetch-depends [00:05:46] [01] [00:00:02] Status www/gitlab@ee | gitlab-ee-17.10.3: fetch [00:05:56] [01] [00:00:12] Status www/gitlab@ee | gitlab-ee-17.10.3: checksum [00:05:56] [01] [00:00:12] Status www/gitlab@ee | gitlab-ee-17.10.3: extract-depends [00:08:25] [01] [00:02:41] Status www/gitlab@ee | gitlab-ee-17.10.3: extract [00:08:34] [01] [00:02:50] Status www/gitlab@ee | gitlab-ee-17.10.3: patch-depends [00:08:34] [01] [00:02:50] Status www/gitlab@ee | gitlab-ee-17.10.3: patch [00:08:34] [01] [00:02:50] Status www/gitlab@ee | gitlab-ee-17.10.3: build-depends [00:27:47] [01] [00:22:03] Status www/gitlab@ee | gitlab-ee-17.10.3: lib-depends [00:27:47] [01] [00:22:03] Status www/gitlab@ee | gitlab-ee-17.10.3: configure [00:27:48] [01] [00:22:04] Status www/gitlab@ee | gitlab-ee-17.10.3: build [00:27:48] [01] [00:22:04] Status www/gitlab@ee | gitlab-ee-17.10.3: run-depends [00:27:48] [01] [00:22:04] Status www/gitlab@ee | gitlab-ee-17.10.3: stage [00:27:53] [01] [00:22:09] Status www/gitlab@ee | gitlab-ee-17.10.3: package [00:29:40] [01] [00:23:56] Finished www/gitlab@ee | gitlab-ee-17.10.3: Success So, somewhat over 19 min build-depends -> lib-depends. After reboot: [00:05:58] [01] [00:00:00] Building www/gitlab@ee | gitlab-ee-17.10.3 [00:05:59] [01] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.10.3: check-sanity [00:05:59] [01] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.10.3: pkg-depends [00:05:59] [01] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.10.3: fetch-depends [00:05:59] [01] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.10.3: fetch [00:06:06] [01] [00:00:08] Status www/gitlab@ee | gitlab-ee-17.10.3: checksum [00:06:06] [01] [00:00:08] Status www/gitlab@ee | gitlab-ee-17.10.3: extract-depends [00:09:37] [01] [00:03:39] Status www/gitlab@ee | gitlab-ee-17.10.3: extract [00:09:46] [01] [00:03:48] Status www/gitlab@ee | gitlab-ee-17.10.3: patch-depends [00:09:46] [01] [00:03:48] Status www/gitlab@ee | gitlab-ee-17.10.3: patch [00:09:46] [01] [00:03:48] Status www/gitlab@ee | gitlab-ee-17.10.3: build-depends [00:26:31] [01] [00:20:33] Status www/gitlab@ee | gitlab-ee-17.10.3: lib-depends [00:26:31] [01] [00:20:33] Status www/gitlab@ee | gitlab-ee-17.10.3: configure [00:26:31] [01] [00:20:33] Status www/gitlab@ee | gitlab-ee-17.10.3: build [00:26:31] [01] [00:20:33] Status www/gitlab@ee | gitlab-ee-17.10.3: run-depends [00:26:32] [01] [00:20:34] Status www/gitlab@ee | gitlab-ee-17.10.3: stage [00:26:37] [01] [00:20:39] Status www/gitlab@ee | gitlab-ee-17.10.3: package [00:28:07] [01] [00:22:09] Finished www/gitlab@ee | gitlab-ee-17.10.3: Success So, somewhat over 16 min build-depends -> lib-depends. So, say, around 18 min for both before reboot and after it. Reproducible for general timescale. During the earlier "bulk -a" www/gitlab@ee got: [1D:19:47:18] [07] [00:00:00] Building www/gitlab@ee | gitlab-ee-17.10.3 [1D:19:47:19] [07] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.10.3: check-sanity [1D:19:47:19] [07] [00:00:01] Status www/gitlab@ee | gitlab-ee-17.10.3: pkg-depends [1D:19:47:20] [07] [00:00:02] Status www/gitlab@ee | gitlab-ee-17.10.3: fetch-depends [1D:19:47:20] [07] [00:00:02] Status www/gitlab@ee | gitlab-ee-17.10.3: fetch [1D:19:47:25] [07] [00:00:07] Status www/gitlab@ee | gitlab-ee-17.10.3: checksum [1D:19:47:25] [07] [00:00:07] Status www/gitlab@ee | gitlab-ee-17.10.3: extract-depends [1D:19:48:19] [07] [00:01:01] Status www/gitlab@ee | gitlab-ee-17.10.3: extract [1D:19:48:50] [07] [00:01:32] Status www/gitlab@ee | gitlab-ee-17.10.3: patch-depends [1D:19:48:50] [07] [00:01:32] Status www/gitlab@ee | gitlab-ee-17.10.3: patch [1D:19:48:50] [07] [00:01:32] Status www/gitlab@ee | gitlab-ee-17.10.3: build-depends [1D:21:11:47] [07] [01:24:29] Status www/gitlab@ee | gitlab-ee-17.10.3: lib-depends [1D:21:11:47] [07] [01:24:29] Status www/gitlab@ee | gitlab-ee-17.10.3: configure [1D:21:11:48] [07] [01:24:30] Status www/gitlab@ee | gitlab-ee-17.10.3: build [1D:21:11:48] [07] [01:24:30] Status www/gitlab@ee | gitlab-ee-17.10.3: run-depends [1D:21:11:50] [07] [01:24:32] Status www/gitlab@ee | gitlab-ee-17.10.3: stage [1D:21:11:57] [07] [01:24:39] Status www/gitlab@ee | gitlab-ee-17.10.3: package [1D:21:16:11] [07] [01:28:53] Finished www/gitlab@ee | gitlab-ee-17.10.3: Success where the load averages were near the FreeBSD cpu count over the time frame. So, it appears that competing for I/O bandwidth with the other builders makes the difference of: around 18 min vs. around 83 min for build-depends -> lib-depends . === Mark Millard marklmi at yahoo.com
