From nobody Sat Apr 12 02:28:27 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 4ZZHYF408Lz5sdYh for ; Sat, 12 Apr 2025 02:28:49 +0000 (UTC) (envelope-from marklmi@yahoo.com) Received: from sonic314-21.consmr.mail.gq1.yahoo.com (sonic314-21.consmr.mail.gq1.yahoo.com [98.137.69.84]) (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 4ZZHYF0znxz3RSY for ; Sat, 12 Apr 2025 02:28:49 +0000 (UTC) (envelope-from marklmi@yahoo.com) Authentication-Results: mx1.freebsd.org; dkim=pass header.d=yahoo.com header.s=s2048 header.b=J0QKrUyL; dmarc=pass (policy=reject) header.from=yahoo.com; spf=pass (mx1.freebsd.org: domain of marklmi@yahoo.com designates 98.137.69.84 as permitted sender) smtp.mailfrom=marklmi@yahoo.com DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s2048; t=1744424923; bh=ymBnqBNV6BhyZvY5o9a9at8eVxIs216WXCehmIFyhxc=; h=Subject:From:In-Reply-To:Date:Cc:References:To:From:Subject:Reply-To; b=J0QKrUyLhb/JuCXj9EMfqElTutZx2Pgnb/kP5/tXJaNIQpTYKKo2Hmron3PdkGsg6odYE6zCYQrRXQ6XljM4CXWt0A9a5qTlugSO8xuhwr3MbdH1ox3ExSOKHlNRzGTgJjXqhAsLDxyb4dlGhv11jZheGJRp8kBE3iybq6/f3+oybnUzF2QyLDagqdqUFRCM3aDkQSoTItmVZDRsCB6squTxML2COgdW8JSi/PhdLBsRpxBl/lVeeNHi32t0y2fV3tcW6K5NkCk/QZIVOq0brcknfCxZATDuYVKc0hyVYN2z7FLyK6uouvU6EtMSzE4+v3tynKGG/IEPnfZq0AxnWQ== X-SONIC-DKIM-SIGN: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s2048; t=1744424923; bh=sqiifUUhH7EXFmMLWg1SGhWOJ9OXBaLvOLVS0cyXdyf=; h=X-Sonic-MF:Subject:From:Date:To:From:Subject; b=e+KjsTyjBOTDz4jIna2jUUQXVo84uYDLL/YywW1bUvHisBf5kf2L8Q5bvlnFkbWNg5iekmYUd7cAFOv5E2imCBaQ9WJO7iB52tuB1bSHN9wiAiGfD974ZJ/X35GJAIWA4Wa3lhvUySDbHkmoymWVTM9LMKcI+rp+vPXHrMImu3fU+hovxw7aqM5XI6p6R9Pmk76lXFT/xMUJ08KMHghjwC/b4kvKbAIPcXg+2C1IbBQU1KcVnVLI2PwYeAxDpeGLBdQCQLUmadWdFCTdQCGjFGWaQVdIOxZDR/LKSKYEK1wysqSuWXj/OXgUPb2/XYHZujIrg8IsPJcbqljhRgr2Kw== X-YMail-OSG: YcYqB0YVM1krZglddhb4fTTruvu0eAjw.7ptB3v9LF7Yj1YlknoN1qU3Ak9c1EZ 48DaYAD5NF3FPoJhJBVNoee7I5ObBa6w6JIwpazfIx4MFL_tS7IRpedvuQN0dBKEQYhmNYhWbhqu 9qhqX.6XkAPOcCq43r1Uf1mJWH_HlZl7UVe3lBsMVvYeRWB6rfUdQDE4o1EviEJEH8MldwxaDn6. AujabEs32Kha12F5NmwQ5hA1cSew.ONGSWgvLVdtlKOWFN2EBFwG16ipSBx7RyWqv8UN7dk7UosO kk6L_4SIb9s3Azc5IsWBqeumOphuWjh_xrfVApjh9WftfctZBl_6mykiv.1y7yE8izfDswUB5P_u q7s3qWXANpmYQJ5SYOA8na1QdIIXIj_ueDcrFsqbJV.533YVy1sBIl6HrvJ4YpCaBkiOPEbJIJh9 0oHXmISqxHOHklcFi24Mt4gIT879l6no6TVu0FQoI1yEmXzBdTok..FD7cLi1TnGUz482_O0tM0d EzV6tCdP6NtZCgHGnyMTtaGbyXL9GuSC1N.MxVzrg.xinc6IXHwRWRAK.PX96DU35_Y9xOfmSitD A.03HXK7XdafE_yV8nQFg56giQ6yZzIyY3bBqBRGVz4rnqstKnd39wHCDySJ4gY6KHShDC03JyN4 Z.JPTwB3BueNiNFcH05K5MMffWLls2S71mT8BFIXqszVhoJgT6KJOioEpoyjAz_Vhwf7Ree_KwuZ rq7xGxVI5B2pW2IoIS1oAPPgt3JOxJFqDcboCYOg7v8_2ZryvPLT33K4OamG7KIDfURyN1mILYD_ xANxesiiJcSjXr8_qkxQMVYonkfsXFfCvgOqEzzUN3eVXjJj832aViQ9w48yB1.kzgR9r3FDEM2A 3_0KPK0SSrE4coMkSpC4qB29M_ZxdIH3Zd5xsCGRQUNrKAHUYwnJQbaSBLmuiw095sqwWXxUwvjl usNWRgDXbVDJe72_yyLEyEtz26tWJU0WI715Cpkt_OIGxPJ0.kB5JPySnWx.DDNpCFMF6hYHeFSh KXyiqcLD9hw1xLiG.AG02tbHzMu9TQFEcGzbzpgBRc3SfZAKS5Y6HcE23iyw7XO2QUXZvLwVRkYk hekCaR09I2KTpFczUc2iNqwBagT80CZvncfubW1w4sRPn22k7TYDV6S.4cu_BHBeio6MrF0BAHni zeyQbZfXsYeL1K91GVh4WW6CuDrHU2gyL28SZb.4JJTHefF4Uyt8twTEZyoZvQ2..2ihK8ENDgFg PZKlNO9fqh6BoeKKzqvV5XJY778uC61cZC1o4Qd8b3NNc_U2cWS_Q8Q3SeJFYr9.yF8aFu353tS8 0eSDP373UQxm.TNwvS.pZdrK4DxKmE5D5oH4QaMRcxmOSJqMo0nOw_WJ_SyA112.4RvrUX5_W6ek pDBXTsIDtxSkGyAp6PkZSIlRSKZJa3Ne2IFWmwJwimgXUNnyKCzrmrtyIaVNld8GtqgdygNTJa5l P72d9XymG0JbsS4_ofahK8C_R1yEerbxFDURTDGsHy.YsqdlUm5CPX6OJ.GjKyNfPHAgZLeUuDVb ikxU2jc5TmPx0gOvu3erFsO.QBOfClYI1DXhID7x9_UT4cXZeRRFqwz8r4oqyDf26.aJlPQKUt0j RWzM89Sh9aJLjIJspCe1MXCft2gb.MmViLGppr1mNsMm_2vQO.qJ83SnJzIv5YmlE4zlZbFcZSsZ bK.w2MYaSRMV6Ou4VtWiYf6RTG5idmZu7vSdCukICegt.sUo3caAD8ILd8BMJpEq3sMQnuUv9JpC WZD3fZdolGwh8E.kP.DLe8WbnSYQHRV28rRD3XhPO1hhfv.Hqah_hC78tB1gPbRPBikPbBMP4i5. NUkoojRWBv2siTvpIYgRJffvLkh0TDieWx9pCVa6gm3c8Qk.Ia89SHUfg5ncXm1e6JqunR2fcCMo jB1iWGh8dGOY__6Bd.xzRNNmmTYcCaFVtNIWWAz9CJmuiqNgvxPE3O9TTa3.16gt9d7E3GLmexU4 rCJRilQayqcZZqD.xSfP9lgIJ5d8j55CC6uggjcsAWUKom7ZsINxBaQgSZT9yO1BHkxaEQPJJhKZ Nd56rgH_5zRV.Q4JbKLfdrcErKhjpy8Y8ifECaW4YLdkWt8RnMuGFuIo93YrgLJesrIk.1Z6XVud oTDb1Woui9cEU5l3EPPZxU4xdPzwkHKDQbze_PL3FDFVG30.sxjWJYXyhXCsZIu.uBBmpBkYI9Vs hs3u82quh.9GYgdOke1Yq3.SXpqKnD5T44NQVvWODyTpl_86ok3o3.p5EE3oYPH0lH0KcYYahdUe BVxu_Kg-- X-Sonic-MF: X-Sonic-ID: b8eca28f-417c-45e1-9352-a637ce3f3862 Received: from sonic.gate.mail.ne1.yahoo.com by sonic314.consmr.mail.gq1.yahoo.com with HTTP; Sat, 12 Apr 2025 02:28:43 +0000 Received: by hermes--production-gq1-74d64bb7d7-sfjhn (Yahoo Inc. Hermes SMTP Server) with ESMTPA ID b71a1fe54aff611bc1d22bd28938baf1; Sat, 12 Apr 2025 02:28:38 +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: <8B070D1D-0524-4DA4-A5C2-EF2CF98C5E15@yahoo.com> Date: Fri, 11 Apr 2025 19:28:27 -0700 Cc: Gleb Popov <6yearold@gmail.com>, FreeBSD Current , FreeBSD Mailing List Content-Transfer-Encoding: quoted-printable Message-Id: <7A1322FA-A118-4F87-9D96-DE8B05E09424@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> To: Baptiste Daroussin X-Mailer: Apple Mail (2.3826.500.181.1.5) X-Spamd-Result: default: False [-4.07 / 15.00]; RBL_SENDERSCORE_REPUT_9(-1.00)[98.137.69.84:from]; NEURAL_HAM_LONG(-1.00)[-1.000]; NEURAL_HAM_MEDIUM(-0.92)[-0.921]; NEURAL_HAM_SHORT(-0.65)[-0.647]; 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]; RCVD_IN_DNSWL_NONE(0.00)[98.137.69.84:from]; 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.69.84:from]; MID_RHS_MATCH_FROM(0.00)[]; RCVD_VIA_SMTP_AUTH(0.00)[]; DWL_DNSWL_NONE(0.00)[yahoo.com:dkim] X-Rspamd-Queue-Id: 4ZZHYF0znxz3RSY X-Spamd-Bar: ---- NOTE on something newly noticed while preparing this (a top post to keep it separate): 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. # 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 pkg 2.0.6 /usr/ports/ context/vintage (default): [00:01:51] Creating pkg repository Creating repository in /tmp/packages: 100% Packing files for repository: 100% [00:01:58] Committing packages to repository: / = usr/local/poudriere/data/packages/release-aarch64-default/.real_1744418553= via .latest symlink So: an around 7 sec delta. pkg 2.1.0 /usr/ports-alt/ context/vintage (alt): [00:17:04] Creating pkg repository Creating repository in /tmp/packages: 100% Packing files for repository: 100% [00:20:34] Committing packages to repository: = /usr/local/poudriere/data/packages/release-aarch64-alt/.real_1744419891 = via .latest symlink So an around 210 sec delta. It is the same Windows Dev Kit 2023. It is the same boot media with 2 /usr/ports*/ trees. Prerequisites had been previously built for both. It is also the same jail: # poudriere jail -l JAILNAME VERSION OSVERSION ARCH METHOD = TIMESTAMP PATH release-aarch64 14.2-RELEASE-p1 aarch64 pkgbase = 2025-03-12 21:11:39 /usr/local/poudriere/jails/release-aarch64 Just "-p default" vs. "-p alt" being different on the command line. "Creating pkg repository" would not involve *-depend activity? More of a general I/O problem? May be a far more time consuming compression technique or some such? Back to the originally intended content . . . 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 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.) >>=20 >> 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.) >>=20 >> 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.) >=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. =3D=3D=3D Mark Millard marklmi at yahoo.com