From nobody Sun Apr 30 07:50:02 2023 X-Original-To: freebsd-arm@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 4Q8JRH4sDXz46SQ3 for ; Sun, 30 Apr 2023 07:50:19 +0000 (UTC) (envelope-from marklmi@yahoo.com) Received: from sonic304-23.consmr.mail.gq1.yahoo.com (sonic304-23.consmr.mail.gq1.yahoo.com [98.137.68.204]) (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 4Q8JRG4rHwz3sCr for ; Sun, 30 Apr 2023 07:50:18 +0000 (UTC) (envelope-from marklmi@yahoo.com) Authentication-Results: mx1.freebsd.org; dkim=pass header.d=yahoo.com header.s=s2048 header.b=PaHrZaCX; spf=pass (mx1.freebsd.org: domain of marklmi@yahoo.com designates 98.137.68.204 as permitted sender) smtp.mailfrom=marklmi@yahoo.com; dmarc=pass (policy=reject) header.from=yahoo.com DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s2048; t=1682841016; bh=YOoe200HacnbBfywZapJrkgkLiUxWYnsNRKevxbTQFE=; h=From:Subject:Date:References:To:In-Reply-To:From:Subject:Reply-To; b=PaHrZaCXD6R3a/v29DM8qhgEVswwDpJ1tf7Q0ZY727MpRhUxdIzRdzvU4psbPpq/MDsGTXUi+kRMtkML7s2Lb1O3A1srOdhc/L8mL4t75mhHt36L4FPWydQ2e2f1E66TW3SXAolXP2lYnoOeP4bfH2fQ6TDD65MwBEDqLZnFmmhFwvhBGYuBDHV+a/JqJrlYUyhN/netIN4eweJy9OQXEaaJzJp2GJQgsp+YZYgcfB0mRbe9GiPI5okaOxiHwPaL3I4lZBzgP71T0qc2Zwx0uosGyyKvtJToqUNGYWbEL1su94QlLfVrCEcH6M4B88s+ANwtEVLXEJCuvk17RC1aSQ== X-SONIC-DKIM-SIGN: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s2048; t=1682841016; bh=kZyvH3ygK1SqV9irDpKYtA84HCwKxKi8/5CQ/A21vWw=; h=X-Sonic-MF:From:Subject:Date:To:From:Subject; b=UrV7huuq2E2OqFhMPhxSHbKiEgOHcfY4h5RFyUiI8ruc24lxmDLbTtDJtp27KEnTTgilvdD1tR3mwa44PoHpa9D70XDGqVSOLMgeF8kbNVHtQVFjjLTcJRCY0K+S9FyTZ9x0ps/x8UDibtlnEt59GrDHVthkrBFA+zCQEY1yoljbF/mITzgDHk7C0/iAgm3vsn2LiZqiEGa/f8Sg3xeOEWc1nFUXYhdV3AKa2UGeSARRrsDnYaCYLBmF5H7b6nNjul1e6BhXs7j0nxIowbeWNPOxDbOheVe0G8Rtoqiv3PrJaLbkXivIZBlRhnp36aU6HCSMoaWxWoQhVy9wdow5Mw== X-YMail-OSG: mFkGbdQVM1lGhrCb7qxlbOZLSA6BJWpCIud8W4te6Bs1gQMNGWKNURFKPekmKzF wt4d6suy0czfJxsuj8.kjepuThLnF8z2tonJ8uyEs6js1MOIr.rKotmq8mtzB3dSaTw_ztRnSgZi hH9tU0fv1IZwu8S96JyiUZwXalMguT58FnhRMiNl4J_mZMFjqV..n1CxC5pzP5liKuVq4tcLytm9 Ks8yFGKa3NHufmvnhCyCvwxEzzbpFNotijYBvvRcdobl0CoACioV8PQfzX6gDP8.uDISoP_T8WyK gcmX3qKG3iMC7GspCK8t.tFziFgs0e4jvNrt2hBu52MKKiYGRy0qJiFrVPK_8_GcRMpVlEUWUvqV 75vAeKx.KsF.fOIosXCq7HeHvZwaM8EpyxrrD4fDakZ.JB7.x8k.H3BbxPWAhT3a8.Md57uvhEij 9b6PKiGB2J5Dp60X.qO6IkxLCekbAb.umq3ZgaqeEOonhIx_zVKn63wmaDaNLfoB4_JmvyHttS9N t743X.EjC9tza1U0KS6PfvIU7SkCpcl.DLisdL06F8hVGuacwJ.WnjM2f_Pp22PJ4qa7SGEVpEGO 0eXT0I7zRtvO0wOQYBv.6pKte7JXqOH61RrFYEGQkVlqIOIDx7KrFLHSVgmjrxzsiBqxSjNiprxS culvrfIHC5VgobxFFUQUPWNSejFGPKUTmFFcrTOGaR_Z8ZEGT0GYfpfLRr3Mkyn6pWRnvMRwpeEW C6vXKiBx9n37I8IOkEfR4R9_hPNLbZ9nu4LdoJ6CxmWN9jJkwSTtspdyQKqj65k6xGxEyN51IfOB YJd.WNf5JDsh18G1VYmmW.cmAmBZ0P8MzkCUVMpIcJRbvbxLdow6NiWAn0XwgQsHefU0BxF7goXc RgRsVYl6543a1NUqM1cPabD2m5g4M1P30D6oCrmT2dturdxy_hYBIXJmDqX8dfqENejASGrDW2oI mxZt54AXGEGxx3J.YjG46BxFGE.oUWbh57MdulcGGrF07g7ydIQH4lOuwtVDH6mIVji1xA52Te8O tRQwDZiLjR8Wy68IDm2a7F0mLIAHPk0br8ysmzGmO2ZjHQcxUaFQ_1LdkJ0euNrnzOtZ6VL70n0X ZkFf4XzQH8EGyjGCdDz1rHjm8nmp3LEoT42WJTiS0nvHXEYzFRzPK73E_Ms0pf_ssEuVz.cp7zKq sMTy03DTpljtrVR1jachMnxOzh5W3zNUCQVpnDtkxTHV4moaOBonEZJxmaCUaXxBqGjEz55hoWP7 JWvi7qJQAwP5_YA1.YAT6bliJO4TP5pgRwIUpRbhYHdzCgf1bhNmNqh13dXqEsU9UU56HvWWRF._ H204DlcetlspUjx0Zfna0fYsgqyOlM7_yvBpzQvw3P7ycdtwmpmt0d7QyEwekV_h.53.QTd6_rU2 bOkpOdr6H7QI7Bebe5MdQ_..BGScau1h21akZ8NNDJ4YDCeRheOlqL6lw14Xz06zmYxxO9Tjnt1Y zIIubZmZ47ROzx_qmJ4J_Kbwjp1B1Wlht0eXb1LmIYsoxFJwmNMel2LNoBn8mwf8z9t1c0f5oma9 p1Xz0wpSLXwcwWJTnRGREpdwO7hKLxdzIoYLzyJS2G4OjE6JH6LxL0ZVxl8aKrb2Xfhfg3Ri_4t0 t_yIhIoFUuDSkO._LU_zfcGq.L.FItrdycFBKHy79RaFKwqoonTskuWY5Xx0sObMPvjMID975Fx. uaRNRidePyHS6j7WPzF2qRBpgaPFIW96lr0Sgu8CHahsr_tXPOpw1pWYiF6n1GLDRoc6PgPmbLwf aNrULHi2StD3OPp6NfVj39a5w5S1RLHHQ7qTLjagqVX1Xp1oB5rg8ewipDciP4oJh5gAMsCITc_v crTklNHCRN.H2iA0jlFPKu3ZTj5a_SlA42FCrCv4L4OvJZ_k2uoGX65yKuaKqQnVK.Lqj68gH37p n_snsMUb9AGoitdQn6wETWTkE6Hekd.q2V9TDlkdioh8EDmQ7G4ZQkQP6yuK57cO8oDIjMU7pXpI 3tAEXSImaS_D3VZG6ot0hNKB1fdCmK3nK7SSzth..8sfIiQ2r0g8K6vt8j5jL3oCXIidsomEwv2g gGhiv3dtn5FyM.k49ocpjjX15_X7lYVrW_9G17XI4a8Lwh025pC63AzgaJw4pQ.uIeoqQQ6L9kPp X8hgpqiLgYY6_.AVSBmD6EOczkh.2GJ1U2kmyBto4KK2DFCWtqSG_tsunF3Mj.fgBaS.EjoGHxTi Xsd8fPQ1IYU7MJ1MRRjxpz7lE597NRAmmhktbNyCq1N2caVodPhHbWHq3z4rMn8WpNe4J6McAVsV Bwh4- X-Sonic-MF: X-Sonic-ID: 110a1bb2-13c1-4169-bc79-053d31d03f1a Received: from sonic.gate.mail.ne1.yahoo.com by sonic304.consmr.mail.gq1.yahoo.com with HTTP; Sun, 30 Apr 2023 07:50:16 +0000 Received: by hermes--production-gq1-546798879c-qtf56 (Yahoo Inc. Hermes SMTP Server) with ESMTPA ID 887f2c2aaf197c4439425249f4901f60; Sun, 30 Apr 2023 07:50:13 +0000 (UTC) From: Mark Millard Content-Type: text/plain; charset=us-ascii Content-Transfer-Encoding: quoted-printable List-Id: Porting FreeBSD to ARM processors List-Archive: https://lists.freebsd.org/archives/freebsd-arm List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-arm@freebsd.org Mime-Version: 1.0 (Mac OS X Mail 16.0 \(3731.400.51.1.1\)) Subject: Re: armv8.2-A+ tuned FreeBSD kernels vs. poudriere bulk and USB3 media: tx->tx_quiesce_done_cv related blocking of processes? Date: Sun, 30 Apr 2023 00:50:02 -0700 References: <7AE28A5B-109E-4C26-9D70-BCA5D49CD79D@yahoo.com> To: FreeBSD Hackers , freebsd-arm In-Reply-To: <7AE28A5B-109E-4C26-9D70-BCA5D49CD79D@yahoo.com> Message-Id: <02DC03AE-E082-4FB5-AA0D-396F64CC23CB@yahoo.com> X-Mailer: Apple Mail (2.3731.400.51.1.1) X-Spamd-Result: default: False [-2.44 / 15.00]; SUBJECT_ENDS_QUESTION(1.00)[]; NEURAL_HAM_LONG(-1.00)[-1.000]; NEURAL_HAM_MEDIUM(-1.00)[-1.000]; NEURAL_HAM_SHORT(-0.94)[-0.944]; MV_CASE(0.50)[]; DMARC_POLICY_ALLOW(-0.50)[yahoo.com,reject]; R_SPF_ALLOW(-0.20)[+ptr:yahoo.com]; R_DKIM_ALLOW(-0.20)[yahoo.com:s=s2048]; MIME_GOOD(-0.10)[text/plain]; ARC_NA(0.00)[]; RCVD_VIA_SMTP_AUTH(0.00)[]; FROM_HAS_DN(0.00)[]; TO_MATCH_ENVRCPT_SOME(0.00)[]; MIME_TRACE(0.00)[0:+]; RCVD_IN_DNSWL_NONE(0.00)[98.137.68.204:from]; DWL_DNSWL_NONE(0.00)[yahoo.com:dkim]; FREEMAIL_ENVFROM(0.00)[yahoo.com]; ASN(0.00)[asn:36647, ipnet:98.137.64.0/20, country:US]; TO_DN_ALL(0.00)[]; RCVD_COUNT_THREE(0.00)[3]; FREEMAIL_FROM(0.00)[yahoo.com]; MID_RHS_MATCH_FROM(0.00)[]; DKIM_TRACE(0.00)[yahoo.com:+]; FROM_EQ_ENVFROM(0.00)[]; RCPT_COUNT_TWO(0.00)[2]; MLMMJ_DEST(0.00)[freebsd-arm@freebsd.org]; RCVD_TLS_LAST(0.00)[]; RWL_MAILSPIKE_POSSIBLE(0.00)[98.137.68.204:from] X-Rspamd-Queue-Id: 4Q8JRG4rHwz3sCr X-Spamd-Bar: -- X-ThisMailContainsUnwantedMimeParts: N On Apr 29, 2023, at 19:44, Mark Millard wrote: > This is based on: main-n262658-b347c2284603-dirty, b347c2284603 > being from late Apr 28, 2023 UTC. (The "-dirty" is from some > historical patches that I use.) The build is a non-debug build > (but with symbols not stripped). World or Kernel had been built > using: >=20 > -mcpu=3Dcortex-a78C+flagm+nofp16fml >=20 > just for testing purposes. (Worked nicely for -j8 buildworld > buildkernel testing for the 4 cortex-a78c's plus 4 cortex-x1c's > present.) >=20 > Monitoring poudriere bulk related activity via top and gstat -spod > I see a lot of the odd result of one process doing something > like: >=20 > CPU4 4 1:39 99.12% /usr/local/sbin/pkg-static create -f tzst -r = /wrkdirs/usr/ports/devel/cmake-core/work/stage >=20 > while other processes sit in the likes of: >=20 > tx->tx > zcq->z > zcw->z > zilog- > select > wait >=20 > But sometimes there is no CPU bound process and the top CPU process is > the likes of: >=20 > 1.24% [usb{usbus0}] >=20 > "gstat -spod" basically shows da0 dedicated to write activity most > of the time. >=20 > After: sysctl kern.tty_info_kstacks=3D1 > Then using ^T at various times, I see a lot of: >=20 > load: 0.48 cmd: sh 93914 [tx->tx_quiesce_done_cv] 7534.91r 11.06u = 22.66s 0% 3800k > #0 0xffff0000004fd564 at mi_switch+0x104 > #1 0xffff000000463f40 at _cv_wait+0x120 > #2 0xffff00000153fa34 at txg_wait_open+0xf4 > #3 0xffff0000014a40bc at dmu_free_long_range+0x17c > #4 0xffff000001448254 at zfs_rmnode+0x64 > #9 0xffff000001455678 at zfs_freebsd_inactive+0x48 > #10 0xffff0000005fc430 at vinactivef+0x180 > #11 0xffff0000005fba50 at vput_final+0x200 > #12 0xffff00000060c4d0 at kern_funlinkat+0x320 > #13 0xffff00015d6cbbf4 at filemon_wrapper_unlink+0x14 > #14 0xffff0000008f8514 at do_el0_sync+0x594 > #15 0xffff0000008d4904 at handle_el0_sync+0x40 >=20 > load: 0.34 cmd: sh 93914 [tx->tx_quiesce_done_cv] 7566.69r 11.06u = 22.66s 0% 3800k > #0 0xffff0000004fd564 at mi_switch+0x104 > #1 0xffff000000463f40 at _cv_wait+0x120 > #2 0xffff00000153fa34 at txg_wait_open+0xf4 > #3 0xffff0000014a40bc at dmu_free_long_range+0x17c > #4 0xffff000001448254 at zfs_rmnode+0x64 > #5 0xffff0000014557c4 at zfs_freebsd_reclaim+0x34 > #6 0xffff000000a1340c at VOP_RECLAIM_APV+0x2c > #7 0xffff0000005fd6c0 at vgonel+0x450 > #8 0xffff0000005fde7c at vrecycle+0x9c > #9 0xffff000001455678 at zfs_freebsd_inactive+0x48 > #10 0xffff0000005fc430 at vinactivef+0x180 > #11 0xffff0000005fba50 at vput_final+0x200 > #12 0xffff00000060c4d0 at kern_funlinkat+0x320 > #13 0xffff00015d6cbbf4 at filemon_wrapper_unlink+0x14 > #14 0xffff0000008f8514 at do_el0_sync+0x594 > #15 0xffff0000008d4904 at handle_el0_sync+0x40 >=20 > load: 0.44 cmd: sh 93914 [tx->tx_quiesce_done_cv] 7693.52r 11.24u = 23.08s 0% 3800k > #0 0xffff0000004fd564 at mi_switch+0x104 > #1 0xffff000000463f40 at _cv_wait+0x120 > #2 0xffff00000153fa34 at txg_wait_open+0xf4 > #3 0xffff0000014a40bc at dmu_free_long_range+0x17c > #4 0xffff000001448254 at zfs_rmnode+0x64 > #5 0xffff0000014557c4 at zfs_freebsd_reclaim+0x34 > #6 0xffff000000a1340c at VOP_RECLAIM_APV+0x2c > #7 0xffff0000005fd6c0 at vgonel+0x450 > #8 0xffff0000005fde7c at vrecycle+0x9c > #9 0xffff000001455678 at zfs_freebsd_inactive+0x48 > #10 0xffff0000005fc430 at vinactivef+0x180 > #11 0xffff0000005fba50 at vput_final+0x200 > #12 0xffff00000060c4d0 at kern_funlinkat+0x320 > #13 0xffff00015d6cbbf4 at filemon_wrapper_unlink+0x14 > #14 0xffff0000008f8514 at do_el0_sync+0x594 > #15 0xffff0000008d4904 at handle_el0_sync+0x40 >=20 >=20 > The system (Windows Dev Kit 2023) has 32 GiBytes of RAM. Example > output from a top modified to show some "Max[imum]Obs[erved]" > information: >=20 > last pid: 17198; load averages: 0.33, 0.58, 1.06 MaxObs: = 15.49, 8.73, 5.75 = up 0+20:48:10 19:14:49 > 426 threads: 9 running, 394 sleeping, 1 stopped, 22 waiting, 50 = MaxObsRunning > CPU: 0.0% user, 0.0% nice, 0.2% system, 0.1% interrupt, 99.7% idle > Mem: 282760Ki Active, 7716Mi Inact, 23192Ki Laundry, 22444Mi Wired, = 2780Ki Buf, 848840Ki Free, 2278Mi MaxObsActive, 22444Mi MaxObsWired, = 22752Mi MaxObs(Act+Wir+Lndry) > ARC: 11359Mi Total, 3375Mi MFU, 5900Mi MRU, 993Mi Anon, 93076Ki = Header, 992Mi Other > 8276Mi Compressed, 19727Mi Uncompressed, 2.38:1 Ratio > Swap: 120832Mi Total, 120832Mi Free, 2301Mi = MaxObs(Act+Lndry+SwapUsed), 22752Mi MaxObs(Act+Wir+Lndry+SwapUsed) >=20 >=20 > The poudriere bulk has 8 builders but has ALLOW_MAKE_JOBS=3Dyes > without any explicit settings for the likes of MAKE_JOBS_NUMBER . > So it is a configuration that allows a high load average compared > to the number of hardware threads (here: cores) in the system. >=20 >=20 > I've rebooted to do a test with filemon not loaded at the time > (here it was loaded from prior buildworld buildkernel activity). > We will see if it still ends up with such problems. It still ends up with things waiting, but the detailed STATE valiues generally lsited are somewhat different. I also tried a chroot into a world from use of -mcpu=3Dcortex-a72 and got similar results. Suggesting that only the -mcpu=3Dcortex-a78c+flagm+nofp16fml kernel is required to see the issues. This even got some examples like: load: 1.20 cmd: sh 95560 [tx->tx_quiesce_done_cv] 2022.55r 3.21u 9.24s = 0% 3852k #0 0xffff0000004fd564 at mi_switch+0x104 #1 0xffff000000463f40 at _cv_wait+0x120 #2 0xffff000001518a34 at txg_wait_open+0xf4 #3 0xffff00000147d0bc at dmu_free_long_range+0x17c #4 0xffff000001421254 at zfs_rmnode+0x64 #5 0xffff00000142e7c4 at zfs_freebsd_reclaim+0x34 #6 0xffff000000a1340c at VOP_RECLAIM_APV+0x2c #7 0xffff0000005fd6c0 at vgonel+0x450 #8 0xffff0000005fde7c at vrecycle+0x9c #9 0xffff00000142e678 at zfs_freebsd_inactive+0x48 #10 0xffff0000005fc430 at vinactivef+0x180 #11 0xffff0000005fba50 at vput_final+0x200 #12 0xffff00015d8ceab4 at null_reclaim+0x154 #13 0xffff000000a1340c at VOP_RECLAIM_APV+0x2c #14 0xffff0000005fd6c0 at vgonel+0x450 #15 0xffff0000005fde7c at vrecycle+0x9c #16 0xffff00015d8ce8e8 at null_inactive+0x38 #17 0xffff0000005fc430 at vinactivef+0x180 (The chroot use involves null mounts.) which is sort of analogous to the filemon related backtraces I showed earlier. The common part=20 across the examples looks to be #0..#11: #0 0xffff0000004fd564 at mi_switch+0x104 #1 0xffff000000463f40 at _cv_wait+0x120 #2 0xffff00000153fa34 at txg_wait_open+0xf4 #3 0xffff0000014a40bc at dmu_free_long_range+0x17c #4 0xffff000001448254 at zfs_rmnode+0x64 #5 0xffff0000014557c4 at zfs_freebsd_reclaim+0x34 #6 0xffff000000a1340c at VOP_RECLAIM_APV+0x2c #7 0xffff0000005fd6c0 at vgonel+0x450 #8 0xffff0000005fde7c at vrecycle+0x9c #9 0xffff000001455678 at zfs_freebsd_inactive+0x48 #10 0xffff0000005fc430 at vinactivef+0x180 #11 0xffff0000005fba50 at vput_final+0x200 There were a lot more nanslp examples in all the alter testing (i.e, those avoided filemon.ko being loaded). Starting from having pkgclean -A'd the ports, the experiments got about the same number of ports built as of the end of the 1st hour. UFS vs. ZFS? Different media types? . . . So I decided to create and try a UFS test context instead of a ZFS one. But the media that was best to update was a U2 960GB Optane in a USB3 adapter, something that would perform noticeably better than my normal USB3 NVMe drives, even with USB involved. This combination maintained reasonable load averages (instead of having long periods of <1) and finish building 172 ports in the 1st hour, far more than the around 83 each time I tried the other device/ZFS combination. NO evdience of the earlier reported oddities. I should also time a from-scratch buildworld buildkernel. I'll look into setting up another U2 960GB Optane for use in the USB3 adpater, but with ZFS. That should help isolate media vs. file system contributions to the varying behaviors. =3D=3D=3D Mark Millard marklmi at yahoo.com