From nobody Sat Apr 12 06:55:41 2025 X-Original-To: freebsd-current@mlmmj.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mlmmj.nyi.freebsd.org (Postfix) with ESMTP id 4ZZPTW37D3z5t0xm for ; Sat, 12 Apr 2025 06:55:59 +0000 (UTC) (envelope-from marklmi@yahoo.com) Received: from sonic311-25.consmr.mail.gq1.yahoo.com (sonic311-25.consmr.mail.gq1.yahoo.com [98.137.65.206]) (using TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 4ZZPTS3rYPz3jv8 for ; Sat, 12 Apr 2025 06:55:56 +0000 (UTC) (envelope-from marklmi@yahoo.com) Authentication-Results: mx1.freebsd.org; dkim=pass header.d=yahoo.com header.s=s2048 header.b="q/9T8+dC"; dmarc=pass (policy=reject) header.from=yahoo.com; spf=pass (mx1.freebsd.org: domain of marklmi@yahoo.com designates 98.137.65.206 as permitted sender) smtp.mailfrom=marklmi@yahoo.com DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s2048; t=1744440954; bh=YJ9gmDmRnrQnU7rpi72Dfu9RKlGLeJOTFc5kYO6j754=; h=Subject:From:In-Reply-To:Date:Cc:References:To:From:Subject:Reply-To; b=q/9T8+dC0HXnw2qBfIdyPmKtS3Bk/as0v9ITWQg4X7NCpiCe4yeDHgnevtZVP2cPPjZSaLmk2/hxzteS0VuLCC4sEYDwOxHS3veNIId1B1N2xh/pKObxxaZn2DGKITqdM7Wwo0tRp73Q1AReXx6SsEUck80gX624TdrzuB7FO+620tgB5C9o+7bGIr6DRKqFoZKg8aAF5xnelNr3m6yH9eckaxzuXxpRkdaJCfeQ/CnWjenHn5Auy2fQMxM+uAIKyJEzKe35+qA900c8KPFPpaXUq02ZBwPS496LDkjaxh/qBw2yHnAAdP06g3PDGX4V5H2ivBJdWwAYNJHgKhTf7w== X-SONIC-DKIM-SIGN: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s2048; t=1744440954; bh=R5VFsCU3onbZmBufLIqS0vKnOIA9BQ80MHaV4eXdlts=; h=X-Sonic-MF:Subject:From:Date:To:From:Subject; b=lXqCElrFQ7rxuxtkRQeKaL08YPnvQN8WZfbioDWv1oMEG64DHA9DdyIM42jX2FT8fDurBr7eeo7XtWWkUenLFu8Qep6w51B9oLxuD4QR9sd82qrdKgPQO4upanw6qZQS2w22JPsYXMBFl4f4+W42rmGSeIg7oB2+ZjjMy9G/cxzHIDLuDXQXE4Fum2X/W1PGEesYT2ezvbx4giazhGQvJud5JVPDG66GuMLVRx2rZe7iLTXPBAAf5SkUi6yRRUjQsOoFjXbcn5oIWKjkW9mDiDkC9nq2s7af7fPP9QMiMSefWl8a6ayiW1n8CPncvi0f+OGPr3SPyrzIK4AmSvvUNQ== X-YMail-OSG: opiG_0QVM1mkE.QiEvZW8bQfmrY3VxoTqwsCERGVwfUWyiXmOWUXX5X1QzibP_s W_7xHh5Z1K04dzyEEgHBej_Bg8DJ6qvg7oSmvmQZ64qUQWPlYjBQwm2FEQZf_Z.jeMmpDUDXDvd3 LcHiNgryDpUi0YwUKSZr6a.CMgzREQIOMCYU1zvF110Mvkp08qOzzRzI3PARauw0W9rqDG12Oe_Y lCS63mae6B78TFAmS1MdVMz7BfCA3T66AOrynGVxbn8y9Im28QMLO.rhPaeJUlniLidDLqdrHlSL bW_y0KNsDT7IQ0ZZ8vtAk6qokucW.mQpsAgrw4pSvgf.xKmgOXgW_i.wlfVrUrg5U9TGcSMdzLFV I8V8Anv4JGq04saZfn0EmQhSXDk0GEkr2HobKL0Jr94ymG4glOER4IZRBpJMc4hcEFUnj_.NoEHc DgVc6LQSUnGxo9sWus0cxpd37H7t5BIZITfSXgopqBanTv3Xh9eWHT.3Fr1fKXlcIXgcnsfxcDkd HEylKprDQbkird_OAoXtYt649vVSmaciYZS3W0Ubovj7c3D1fTiZJCFGpZEA1tt2wkAjs7jWXvMY mCUTTa59IMvo8PL3rMB.DfR15KC4UOZdPBQ72iTQVibOhoFpoLTcTa5xsjaC80cw0FWT5vFTZu3d lNgPotN8SKEocdpp.7_EZCnG5u.huKJLQQ6zC4Qfj0KZXgsAHv4Wu3YQbh6zoW9xXzmmKvgewZbV Hgfz1U6fJBO0bmyr4PNn_N5tHQF7CBMdfF.aO1Y6Xqze_H_Ukqw8.ftMAbDoE9iCLvyYrLZMxUEr wf4ULfmiA9D7S9vFwl4vW9DrVeCC.533KqUKGb4YQ5WxwFslrQk5hSVoRGEPOLyqdu3snomxLFVx mT.DqQDPLAXKUU.fuZUrM2aCjcC3Va3l8syTI7mYLOOvC9dP1q6P781K6Eg6OG8GFr7JqtbyJlHL dEMMWKgPSgaBULlaPt4ag5D9QFGf9djYe5EDbBrprxgWkJCOzbH9Q6upwN38kWH6e5v2JksoO2G6 mekIqWzdeFlORRxA9b2FD54R0DS1SagxVChtxIuHaa5yVArN6.5fIHHsvttchaoU0ugb1Wq9xoMN 5Ilue_AedCdkPqgRZ5tPRM8NNpQElugct5TQX.LkIhr3o4c3oDkzEWOnGyrEwIhBn.Cw8wZ85e1U tUYI1A60EG4IPSosMm2v.LmpYzg608dpFPxAsDoaWLw3DX2ygtfURgyRe7MjtwhpxxDsl8n3FUAM vSuxcAWWIJ.Kwa1Ymj2oaesXw4Itj68oPavIA3ZVq6jfExemLbC3_r_9gkch.Io3auo4fKLGhX7i ae0rAop_Eu7A50jcyGVRQV1zz2ffEg7yKkEu1oQcyTsRNYa_OTsSyvDb2TXXN8h6DblARALxcB1a 2.Si3T7shwImyS9EgwBlQST79rh_P23fWmDMml6BscbTLQ31PK0E7GuiuBQOllB60h56zTPHqkh_ Q.KV7yJ2zhc9z.2__UnYui.yjodU5R.Yo3iMQJZA7Rq.A9qXkaUi3jHI5Hqqg2ud6eEHvE4GUVxC 6JkUynKycK.7tJtmE.1uFY3sL2QF8crOaNgr7.qesi3GpPxtUkvhCgT2O7EkvFh2KC3yF1GLFfAI SnLVMBdEu5FwNczxUCoy2a4tPw.6hMNtYMw18rrbsFgMqo1CuSwVjCRAVIcK.4kfbA6TyTMMdiuK BBerrL4Vz_Mo04vJw5MokrHFTpaEzHka29jQB_TzHq_WXHcqTo7QszE95PmzpE06fgTImdrUqfA1 jAo04mGMdgQHJzb78N0N2FBjDSMuShGsFK85HgDFLpT9jyWPIQZq54v8n1TAnXOuqq4GfOh_WKGa B68tK.CraUjbucHHeIiGw1Al1OIDzXriZYH3KHelowcK2cK2nvgfMALFZUGWy.EeyxAE_fjLp3bm j2cN0RGK_G200eouDLpnUPVnXVjjVoyC9WKeBURy2yUzhuNy.RxyYXPtduJtVRtUKDkLOx5m9P27 z_VG.wYFCSNW6WWwOWJcy9HGLV78e4KZJ6_0lTIuVO3U58FgbivsY_lGg3SKS8zLZfaYIkHOwbEw 6eSiTUcqWxRtD5QGKRe8XafMpUhXD41Tc9qUtImUeRB03FuJtue_gJYRQS0MzmhXTxWqFLZJnJyb YguAK1chEW7zvgVeZIvSFNBR_NuynHWxX..kp9j2j7w51bPGsw4cMTeGbvjGUJtCzvaEFgaeXHNE Kxe5ymTseps4k17gk1yHPlKGFz4ReykLfbAieAJm2_hWzDX5saIjGfgYNmBMPin0KuqPhvugWmk2 NQW8- X-Sonic-MF: X-Sonic-ID: c0e389ba-3dde-4b82-998c-abcaedc2bbeb Received: from sonic.gate.mail.ne1.yahoo.com by sonic311.consmr.mail.gq1.yahoo.com with HTTP; Sat, 12 Apr 2025 06:55:54 +0000 Received: by hermes--production-gq1-74d64bb7d7-4jn9v (Yahoo Inc. Hermes SMTP Server) with ESMTPA ID b4fb2d8eb1ac7767d56e0a6cff00cd20; Sat, 12 Apr 2025 06:55:52 +0000 (UTC) Content-Type: text/plain; charset=us-ascii List-Id: Discussions about the use of FreeBSD-current List-Archive: https://lists.freebsd.org/archives/freebsd-current List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-current@FreeBSD.org Mime-Version: 1.0 (Mac OS X Mail 16.0 \(3826.500.181.1.5\)) Subject: Re: UPDATE: pkg 2.1.0 looks to be making official bulk builds of packages take much longer [reproducible examples notes] From: Mark Millard In-Reply-To: <7A1322FA-A118-4F87-9D96-DE8B05E09424@yahoo.com> Date: Fri, 11 Apr 2025 23:55:41 -0700 Cc: Gleb Popov <6yearold@gmail.com>, FreeBSD Current , FreeBSD Mailing List Content-Transfer-Encoding: quoted-printable Message-Id: <6C67E39F-3634-4AF6-95EC-46159E7391E5@yahoo.com> References: <8E2FBAD3-EF6F-4D99-A340-21F8FD19AE0F@yahoo.com> <84FBBAF8-025E-4B9D-9797-51735567A8DB@yahoo.com> <366E27FD-FA5B-4BF8-B6C4-6C495DB289C5@yahoo.com> <7ziazrj7szuqhov3oppjbh3jyu3f2p2owntv4oxprelrdjzc6u@hkuf5szf3zwy> <8B070D1D-0524-4DA4-A5C2-EF2CF98C5E15@yahoo.com> <7A1322FA-A118-4F87-9D96-DE8B05E09424@yahoo.com> To: Baptiste Daroussin X-Mailer: Apple Mail (2.3826.500.181.1.5) X-Spamd-Result: default: False [-4.29 / 15.00]; RBL_SENDERSCORE_REPUT_9(-1.00)[98.137.65.206:from]; NEURAL_HAM_LONG(-1.00)[-1.000]; NEURAL_HAM_SHORT(-0.98)[-0.979]; NEURAL_HAM_MEDIUM(-0.81)[-0.807]; MV_CASE(0.50)[]; DMARC_POLICY_ALLOW(-0.50)[yahoo.com,reject]; R_DKIM_ALLOW(-0.20)[yahoo.com:s=s2048]; R_SPF_ALLOW(-0.20)[+ptr:yahoo.com]; MIME_GOOD(-0.10)[text/plain]; TO_DN_ALL(0.00)[]; FREEMAIL_CC(0.00)[gmail.com,freebsd.org]; FROM_HAS_DN(0.00)[]; ARC_NA(0.00)[]; FREEMAIL_ENVFROM(0.00)[yahoo.com]; RCVD_TLS_LAST(0.00)[]; FREEMAIL_FROM(0.00)[yahoo.com]; MIME_TRACE(0.00)[0:+]; DKIM_TRACE(0.00)[yahoo.com:+]; ASN(0.00)[asn:36647, ipnet:98.137.64.0/20, country:US]; DWL_DNSWL_NONE(0.00)[yahoo.com:dkim]; TO_MATCH_ENVRCPT_SOME(0.00)[]; RCVD_COUNT_TWO(0.00)[2]; FROM_EQ_ENVFROM(0.00)[]; RCPT_COUNT_THREE(0.00)[4]; MLMMJ_DEST(0.00)[freebsd-current@freebsd.org]; RWL_MAILSPIKE_POSSIBLE(0.00)[98.137.65.206:from]; MID_RHS_MATCH_FROM(0.00)[]; RCVD_VIA_SMTP_AUTH(0.00)[]; RCVD_IN_DNSWL_NONE(0.00)[98.137.65.206:from] X-Rspamd-Queue-Id: 4ZZPTS3rYPz3jv8 X-Spamd-Bar: ---- On Apr 11, 2025, at 19:28, Mark Millard wrote: >=20 >> NOTE on something newly noticed while preparing this >> (a top post to keep it separate): >>=20 > . . . > NOTE on something newly noticed while preparing this > (a top post to keep it separate): >=20 > In looking to provide more detailed timing comparisons with > pkg 2.0.6 I noticed another context with a sizable delta > timing difference for building the packages, here using > www/rt50 as an example, just the one package being > built in each case. >=20 > # poudriere ports -l > PORTSTREE METHOD TIMESTAMP PATH > alt null 2025-04-06 14:15:11 /usr/ports-alt > default null 2021-04-18 02:05:47 /usr/ports >=20 > . . . The top-posted note was a dumb mistake on my part: Only /usr/ports-alt/ has a partial "bulk -v -a" set of materials. /usr/ports/ just has specific tested items built, with their prerequsites. (I do not have room on the media for two "bulk -a" storage usages at once.) So of course /usr/ports-alt/ has a lot more involved for its "Creating repository in /tmp/packages" and takes a lot longer. Time for me to try to get some sleep . . . The originally intended content below still applies. >=20 >=20 > Back to the originally intended content . . . >=20 >=20 > On Apr 11, 2025, at 14:04, Mark Millard wrote: >>=20 >> On Apr 11, 2025, at 11:39, Mark Millard wrote: >>=20 >>> On Apr 7, 2025, at 08:14, Baptiste Daroussin = wrote: >>>=20 >>>> . . . >>>> the problem we have is the >>>> performance changes depending on what is happening in parallel on = the machines. >>>=20 >>> 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. >>>=20 >>> 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. >>>=20 >>> 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=20 >>> 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. >>>=20 >>>> which makes the performance issues invisible on local poudriere if = you want to >>>> test it on port A or port B, >>>=20 >>> 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). >>>=20 >>>> 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. >>>=20 >>> I've provided examples of such . . . >>> (time intervals shown are from the aarch64 >>> Windows Dev Kit 2023 with just the one >>> builder active) >>>=20 >>> www/rt50 >>> build-depends: 00:00:27->00:08:46 >=20 > More detailed comparison/contrast of non-parallel builds: >=20 > A pkg 2.0.6 vintage of ports tree on Windows Dev Kit 2023: >=20 > [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 >=20 > A pkg 2.1.0 vintage of ports tree on Windows Dev Kit 2023: >=20 > [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 >=20 > (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.) >=20 >>> devel/py-inline-snapshot@py311 >>> build-depends: 00:00:01->00:00:55 >>> run-depends: 00:00:56->00:01:47 >=20 > A pkg 2.0.6 vintage of ports tree on Windows Dev Kit 2023: >=20 > [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 >=20 > A pkg 2.1.0 vintage of ports tree on Windows Dev Kit 2023: >=20 > [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 >=20 > (Again longer 2.1.0 times vs. previous 2.1.0 times.) >=20 >>>=20 >>> mail/mailest@nox >>> build-depends: 00:00:01->00:00:28 >>> run-depends: 00:00:30->00:00:59 >=20 > A pkg 2.0.6 vintage of ports tree on Windows Dev Kit 2023: >=20 > [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 >=20 > A pkg 2.1.0 vintage of ports tree on Windows Dev Kit 2023: >=20 > [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 >=20 > (Again longer 2.1.0 times vs. previous 2.1.0 times.) >=20 >>>=20 >>> devel/dwarves >>> build-depends: 00:00:05->00:02:23 >>> lib-depends: 00:02:23->00:02:42 >=20 > A pkg 2.0.6 vintage of ports tree on Windows Dev Kit 2023: >=20 > [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 >=20 > A pkg 2.1.0 vintage of ports tree on Windows Dev Kit 2023: >=20 > [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 >=20 > (Again longer 2.1.0 times vs. previous 2.1.0 times.) >=20 >> net-mgmt/fastnetmon >> build-depends: 00:00:03->00:00:42 >> lib-depends: 00:00:42->00:01:29 >=20 > A pkg 2.0.6 vintage of ports tree on Windows Dev Kit 2023: >=20 > [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 >=20 > A pkg 2.1.0 vintage of ports tree on Windows Dev Kit 2023: >=20 > [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 >=20 > (Again longer 2.1.0 times vs. previous 2.1.0 times.) >=20 >> (See later below.) >>=20 >>> 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. >>>=20 >>>> 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. >>>=20 >>> Try some of the examples that I've provided? >>>=20 >>> 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. >>>=20 >>> An example that you might want is my >>> providing more examples of lib-depends >>> with non-parallel timings. >>=20 >> 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) >>=20 >> [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 >>=20 >> (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.) >>=20 >>>> I know what is new and what causes the performance penalty, but not >>>> which part is causing the super extra penalty on the cluster. >>>=20 >>> Various examples reproduce the timing issues >>> outside the cluster and without the parallel >>> builds. >=20 >=20 =3D=3D=3D Mark Millard marklmi at yahoo.com