From nobody Sun Aug 08 22:53:25 2021 X-Original-To: freebsd-toolchain@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 B9CFC174EEBC for ; Sun, 8 Aug 2021 22:53:37 +0000 (UTC) (envelope-from marklmi@yahoo.com) Received: from sonic306-21.consmr.mail.gq1.yahoo.com (sonic306-21.consmr.mail.gq1.yahoo.com [98.137.68.84]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 4GjZJJ3np6z4c2n for ; Sun, 8 Aug 2021 22:53:36 +0000 (UTC) (envelope-from marklmi@yahoo.com) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s2048; t=1628463209; bh=NZiCZky5osoU8OlSdf7Ihsm4UZK6fvY6qMsGm8Oinuo=; h=Subject:From:In-Reply-To:Date:Cc:References:To:From:Subject:Reply-To; b=Oc+rVB0fzpizttxZtsQLkkWt8Y+yBWBwl/3y6jiT6BPvyhlgFnx2DbapXCy8eKGntPPLEEoGSUyG9jCm3pPhXfy0qICGDxPiX5I+aP8HS1mGojMDdsRz6rnvp/nv3hS1L2ZLfIzhVrttEq/V6Z07j3D8FUGoj9aV9c4251SLmsRNSipmJe/E1CqF9vhAa5YXO/7kd3WCWl6woR1TFUphcd8F7vyqrOvUJmM+M0N+N2VFXaa4IvwXfvdGMRdOE1OMhk0t0QaU/lsGt67YFfiMostQNZS+PUq09/H1uO965LOl+GQd+bB/HaoB9Lr0pxUGyRooZVektglMuBS9ovbFYw== X-SONIC-DKIM-SIGN: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s2048; t=1628463209; bh=qBOcO4aPgliD/mJZXDsBVOJXpcwRSJHstufmDkdl7VW=; h=X-Sonic-MF:Subject:From:Date:To:From:Subject; b=o2bzrGP69ftX0LoeL6CcZXCVIF3xa7owUL0jUhB7Dd+gtQeuTgDJ3WRoQEP7UuVdckw4OqVeojnolKwheQmECFmAsdrx1wOWef66GsRgao+1ILGt/BW9mdU+7Tf0odjmQv93Wwl6s7VXYlO5g6hDfyLKJi/RYgMeJKFmeh2oMDh3lzubNytrIjgFma8CEbeapfTs6DnmVHPRChapyvQek2Azx4SJK15xXINRlJ3ZFbeXyjKNDC9FaktJCjNm5jg6LIK2kINB1UTEjhyp4Z2bhKCwu2SSWp3rfJY0jLZQXwo7ayGyeZCbCsL9ycHs8QUAXhCNpwNfh2+/HL6ZQVaPdw== X-YMail-OSG: zwRN34kVM1kSz__MGDRGUn9Z2lm.c6gsKO8Hgghvbe4SGqKNg3NUxl2NfPWO953 IUKQqQUmoFM9S5G3RiDwdjZhQK6k8nBq6f9MAyhS8zhtL_u.EOKYweVRvbX1jS8s2Tm16KkvPEX3 crOgJBIuqh12JQ11q8RS9_afnq5Dqbjztr9ZEEywZuF17Uf9mroQrgdCeJUkUndVN5K_w3ntfEix iWxbH1pZRSofRvLcwb.gBYJqqu6HmuSymsXU8QFsoCKhIH05ycWMhpWrXiiV9ACH6U69Q0F4Cddo Kqbv.LGzdXBSwFvMhK.74_uguuy9nKihyIR.XRSEna8S.ysDrzqlwNGI3lGMXNPCC0hf0HjRyzae Y3UsGFQmOudXb2ZKrHpub9RBvWIzY3BehzwAto.UQhfRL4_zJBGWeevpPzSg7mbhirRlPRaYsBol raPtE4cR5jFiII68tfi3xaGzcpdLWDkzdONk4fEQyRhpn3fUT3z6KKUhRORo9mcAC4PNKJwSp9LP MyzagBnCbSbPZ88CIV_Ear6gOINdwjVAv3bPpqcrrbcbkU3DpD1itqzSIl2SOUcJiNU2E7cnTdBa AwI49fw6CmqsN5I9rA66nzKc2bFHF6h8rV2L3QaWllXlEIq9FRCxKmfRZJky25pqLRN6lH4v95_6 tcYtN90wT34p7JKlBE14z.BzyGSjN8VioHBG5wJ8jPIenC1acfS3qYZJaOoTjzEJKTezWZVQKi7F 3DVEZ266RT1MTfY6kANFCtV_mVytRlvEM0N63I..Axzh2YkvrPUnO.aaHuYRS_Wyzt1ZBQRu_i6q TgWt_wCwgT2Xlte8u1xDMHx5sBFV4VDh5NjlSR8bFwWA8_dogUKGVYYI_iBFgYUHqydeukdYymDV 9gJvZA3Lkwokq8XyiwZbPX0F8XE.pYacqT5Vu0_FXuw32SpRp4j.tZ6UbmKlirVNa_lY6M4mPUka LJ5UTVyyzVkBIvjMvABbeWeafPrKhWKBaWiUmffGnOnUs6sFGPvxgrVlxvwMsZ5LRXW_6luIKhNy Fb9BghaoB9_Oxc870UkhumZyOkIk43QhdGgN4SFIfJPvyTp6M4XFW0dsJPCRGDAYEuz_jxPa_g79 0i7_x7GqtLDtRiE3VPnKZviFFwqzktJY8WuySP7hHw0e9ktHWoalYiLxeJ3tg7.s0m8PSL8v5Oly .7DVbLoIonYlTw8uhs2pHwtxezwHkiJSyNF1Glr_fXPdfTDAQ7.B7cqNK.REzb_1fKxmnjacTq49 mfR3Y_cdpfPG.exFRI75.uqlmhm3XUHLZVERVfctvUh0imh6d4t95_l0brh3ziF3Fz738E9lqvtG 3eBCM4XpuYK3jJlKAwwVIYsJDPh6HkAycK82YRr3eyn.YYiZEncO41anY.mfwsmcn35wCtBgAJ5m CRn82Dhk1Fixh37OQkAx240R3s3kgnIw2FHqZX1prrcy5.8fPt_w_LX_AiGfQuiKKch7KGqeXP3Q lvVW8_duGMdkcCN6QiFRuDGA1ALCrrYr7fnuHvYdkryLaTHI5kQ5guN1xz6_kZk3hoVbdSxofEY1 48n16O90S2RKueLSnwhi8hYq3muL5QQk5bnp3exy6EnGx.xr1K0INwDLfANvtbt2uIqkdBZVD.17 WOJK4QZjH5X1VMqxrOwHAylNfBZrmwZCUPTwPinNXvR_exJn2cdc_TTBh_IuL9hLHNy8wGjrGTCV .GzcU7FmSXk5Pa8pw2PgzFbc4wq4GlzITxVX3bV38qmfU7b_4pbyo1Jp4IFpzuzUq.LC4YvGdPeW t9kBdSEIluSqHklyfglA4p9Xu1Ws1BGlE7MWa0CMmeHfyDebuhQwyyV878U4BI2ndArOBpDYTNFR 7PaaBZNGUnbzvrLUE2tOlX.gCONdF4mS5PX.X2PND.NvWt_WKWlhvnbQG_jSi.7bs2ep2tR6KZJq gLqnnGgcc4MhDrXGFJu5pnt4W22reTbY8hJ2GRWdEfT8442_abPsYPd4y_N9JSoULukiTdzo7DnL TZboDrbSD.UeY4Gm.oiYRl62l0ETBicwVQ212c1Q27mIuT_VeJepxA6opKZMwoL2UFXfHob78uev t1XiMXKoeGfurkcXvP_gLtPoPA4M56RuGCgHp54oDLrEKBec36apYDG2Ew7GPjGJUWdffQdH63X9 fJfMEIQgxKlywvH9t5_2Q1ipRy4HMZ9ch3eJN51vghf7OzlvKJyKc_0A8X7WfRMmfPVV5qIiwuyR xlXWeUNFpF2EaSfHhiinQ0L1GsbKwuBjTjrjur0AE_IdzzblSZKmKCf6qJ6DhTuETEqEUHRiLADD nVyRSuVNh_1v9btvyuZfUJZ7GK7byfXmoGeQSEcaVezNBZACS8FOY4rYoNSnU6iMgPjFlzkjDV4o WwzhAt2gg7Dd_McjhyZXt7ZpyeGKVxyv3vfq9VHyNe2OEFdZqOMjOQx9kzg.MX7JTP7sFfdrGczv 9xZc1EvyzxCtsLoJCrHugRtQRCayfV0ZvJeVRZGrTGifh8brJaYmun2kR5h302QB3Z16KcAimlG_ HFKmYrsm_lbUPr_ANFMPOd7FAQJ7LGAcvcKaweMDooQYlUhr8OHqkY4Eayj4njucwzdfhB3nhryJ 9.7Fant1lfNFujQRztsL5zuCeW0PgwsuwyFrexGG1b8NtBFArLRlSh1yfBZd1PRU- X-Sonic-MF: Received: from sonic.gate.mail.ne1.yahoo.com by sonic306.consmr.mail.gq1.yahoo.com with HTTP; Sun, 8 Aug 2021 22:53:29 +0000 Received: by kubenode531.mail-prod1.omega.gq1.yahoo.com (VZM Hermes SMTP Server) with ESMTPA ID 8415e3e64cf23e281021c71935b0f895; Sun, 08 Aug 2021 22:53:26 +0000 (UTC) Content-Type: text/plain; charset=us-ascii List-Id: Maintenance of FreeBSD s integrated toolchain List-Archive: https://lists.freebsd.org/archives/freebsd-toolchain List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-toolchain@freebsd.org X-BeenThere: freebsd-toolchain@freebsd.org Mime-Version: 1.0 (Mac OS X Mail 14.0 \(3654.120.0.1.13\)) Subject: Re: FYI: Over 2 hours spent (so far) in /usr/local/share/poudriere/processonelog.sh executing bzgrep commands for www/chromium failure X-Priority: 3 In-Reply-To: Date: Sun, 8 Aug 2021 15:53:25 -0700 Cc: FreeBSD Toolchain Content-Transfer-Encoding: quoted-printable Message-Id: <74DE7FBF-31E4-4EAB-B923-1AA3A150DA6F@yahoo.com> References: <00FAF070-71DE-40B6-8D63-C1E74FFCD08C.ref@yahoo.com> <00FAF070-71DE-40B6-8D63-C1E74FFCD08C@yahoo.com> <270299435.875261.1628285088620@privateemail.com> To: linimon@portsmon.org X-Mailer: Apple Mail (2.3654.120.0.1.13) X-Rspamd-Queue-Id: 4GjZJJ3np6z4c2n X-Spamd-Bar: --- Authentication-Results: mx1.freebsd.org; dkim=pass header.d=yahoo.com header.s=s2048 header.b=Oc+rVB0f; dmarc=pass (policy=reject) header.from=yahoo.com; spf=pass (mx1.freebsd.org: domain of marklmi@yahoo.com designates 98.137.68.84 as permitted sender) smtp.mailfrom=marklmi@yahoo.com X-Spamd-Result: default: False [-3.44 / 15.00]; RCVD_TLS_LAST(0.00)[]; ARC_NA(0.00)[]; R_DKIM_ALLOW(-0.20)[yahoo.com:s=s2048]; NEURAL_HAM_MEDIUM(-0.94)[-0.937]; FROM_HAS_DN(0.00)[]; TO_DN_SOME(0.00)[]; FREEMAIL_FROM(0.00)[yahoo.com]; MV_CASE(0.50)[]; MIME_GOOD(-0.10)[text/plain]; R_SPF_ALLOW(-0.20)[+ptr:yahoo.com]; NEURAL_HAM_LONG(-1.00)[-1.000]; TO_MATCH_ENVRCPT_SOME(0.00)[]; DKIM_TRACE(0.00)[yahoo.com:+]; RCPT_COUNT_TWO(0.00)[2]; HAS_X_PRIO_THREE(0.00)[3]; RCVD_IN_DNSWL_NONE(0.00)[98.137.68.84:from]; DMARC_POLICY_ALLOW(-0.50)[yahoo.com,reject]; NEURAL_HAM_SHORT(-1.00)[-0.998]; FROM_EQ_ENVFROM(0.00)[]; MIME_TRACE(0.00)[0:+]; FREEMAIL_ENVFROM(0.00)[yahoo.com]; ASN(0.00)[asn:36647, ipnet:98.137.64.0/20, country:US]; RCVD_COUNT_TWO(0.00)[2]; MID_RHS_MATCH_FROM(0.00)[]; DWL_DNSWL_NONE(0.00)[yahoo.com:dkim] Reply-To: marklmi@yahoo.com From: Mark Millard via freebsd-toolchain X-Original-From: Mark Millard X-ThisMailContainsUnwantedMimeParts: N On 2021-Aug-6, at 17:39, Mark Millard via freebsd-toolchain = wrote: > On 2021-Aug-6, at 14:24, linimon@portsmon.org linimon@portsmon.org = wrote: >>=20 >>> On 08/04/2021 4:43 PM Mark Millard via freebsd-toolchain = wrote: >>> it has spent over 2 hours (so far) doing: >>>=20 >>> /usr/local/share/poudriere/processonelog.sh activity ( = /usr/bin/bzgrep 's ) of/for: >>=20 >> fwiw processonelog.sh is not part of the toolchain per se. It is a = script that is part >> of poudriere. >=20 > poudriere clearly is not part of the buildworld buildkernel > support. >=20 > Since poudriere is used as infrastructure for building > ports into packages, including use on one or more > aarch64 systems for such, I took a guess that toolchain > was more appropriate than ports for what list to use. > Sorry if I guessed wrong. >=20 >> I have maintained it in various incarnations over the years. >=20 >> One of the things that I have tried to do is minimize the time the = script takes in a run >> over the errorlogs for an entire build. These generally complete in = around a minute or so. >=20 > Until attempting www/chromium builds, I'd never noticed > the time frame but in this case I was monitoring with top, > as well as waiting for pouriere's next output after it > reported having saved the wrkdir. >=20 > In the end it was about 2 hr 50 min. Part of this is > likely just the size of a log file from a www/chromium > build attempt that gets near the end. >=20 > The actual log file is not compressed and can be looked at > with just less or more or the like. Such is how I normally > take a preliminary look at build failures. >=20 >> You will need to figure out how big your logfile is, and compare it = to the size of a >> successful logfile, to figure out what is going on. >>=20 >=20 > Unfortunately the system involved is down/not-accessible > for about a day or two. So I'll not be able to check > details for a while. >=20 > The www/chromium build is huge and my original report > lists the size of the log file in the "ls -LTld" output: > 153683812 . So, between 146 MiByte and 147 MiByte. >=20 > A successful build's log file would be larger. The build > only made it into the 94% range for what ninja reports > about steps executed. (Unfortunately, rebuilds use > different alternative orderings that satisfy the partial > ordering criteria. So build to build varies. I've also > seen 77% for the same failure on the same file.) >=20 > For reference: the (root) file system is on an Optane > 480 GiByte in the PCIe 3 slot and is a ZFS file system. > The system has 64 GiByte of RAM. The swap partitioning > is on the same media. >=20 > For reference: > Using USE_TMPFS=3D"yes" lead to the tmpfs for the wrkdir > involved being over 99000 MiByte (so somewhat under > 100 GiByte). The system configuration was sufficient to > not run out of swap/paging space, 64 GiByte of RAM + 120 > GiByte of swap-space. I've since adjusted to just have > USE_TMPFS=3D"data" now that I know of an example of such a > huge wrkdir. (lang/rust ends up with a small wrkdir > peak size, by comparison to www/chromium anyway.) >=20 >=20 > Until I again get access to the system, that is about > all I can report. Here is a "time -l" for one of the bzgrep's that is involved, the first: # time -l bzgrep -qE "(Error: mtree file ./etc/mtree/BSD.local.dist. is = missing|error in pkg_delete|filesystem was touched prior to .make = install|list of extra files and directories|listof files present before = this port was installed|list of filesystem changes from before and = after|Error: Files or directories left over|Error: Filesystem touched = during build)" = /usr/local/poudriere/data/logs/bulk/main-CA72-default/2021-08-03_22h54m48s= /logs/chromium-91.0.4472.114.log 806.63 real 806.63 user 0.19 sys 2476 maximum resident set size 20 average shared memory size 8 average unshared data size 128 average unshared stack size 496 page reclaims 0 page faults 0 swaps 0 block input operations 0 block output operations 37521 messages sent 4691 messages received 0 signals received 7138 voluntary context switches 8536 involuntary context switches Using grep directly is not much different for the times: # time -l grep -qE "(Error: mtree file ./etc/mtree/BSD.local.dist. is = missing|error in pkg_delete|filesystem was touched prior to .make = install|list of extra files and directories|list of files present before = this port was installed|list of filesystem changes from before and = after|Error: Files or directories left over|Error: Filesystem touched = during build)" = /usr/local/poudriere/data/logs/bulk/main-CA72-default/2021-08-03_22h54m48s= /logs/chromium-91.0.4472.114.log 804.02 real 803.86 user 0.18 sys 2476 maximum resident set size 19 average shared memory size 7 average unshared data size 127 average unshared stack size 158 page reclaims 0 page faults 0 swaps 579 block input operations 0 block output operations 0 messages sent 0 messages received 0 signals received 2432 voluntary context switches 9089 involuntary context switches =3D=3D=3D Mark Millard marklmi at yahoo.com ( dsl-only.net went away in early 2018-Mar)