From nobody Sun Oct 16 22:20:41 2022 X-Original-To: freebsd-fs@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 4MrF3R3DPTz4gDRw for ; Sun, 16 Oct 2022 22:21:55 +0000 (UTC) (envelope-from void@f-m.fm) Received: from wout3-smtp.messagingengine.com (wout3-smtp.messagingengine.com [64.147.123.19]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 4MrF3Q6RlFz3Ych for ; Sun, 16 Oct 2022 22:21:54 +0000 (UTC) (envelope-from void@f-m.fm) Received: from compute3.internal (compute3.nyi.internal [10.202.2.43]) by mailout.west.internal (Postfix) with ESMTP id C095832004F8 for ; Sun, 16 Oct 2022 18:21:53 -0400 (EDT) Received: from imap46 ([10.202.2.96]) by compute3.internal (MEProxy); Sun, 16 Oct 2022 18:21:53 -0400 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=f-m.fm; h=cc :content-type:date:date:from:from:in-reply-to:in-reply-to :message-id:mime-version:references:reply-to:sender:subject :subject:to:to; s=fm3; t=1665958913; x=1666045313; bh=rEDhLvUrM8 wofSeTARl6W0jXDeHVDxLIUCYfuv2y/cQ=; b=jYTV6JuvTl8wHK4KkycU48oSsm wWH1+sOV9k15jNiGKkacVra9/sNJtgaypWOxQHz7BwNOTcGCNucH7oIS58n1IQDN OU2Y5YGQOKpsDatK73crydfxYNwL+Yq+jI2CmDfF7S3k8Z53MfKaY935rzYhm0aI scPlQuvze6o33eKhMjsfHVoCjJR2uTbpWH7WQjWB4bo1EUa2oaG+YZ1qhPut5EPk +9J7B8qU+8TDl/5plqS4iBwJbcU2ftGPnquqIhkkOGZLadoW1nNk3Bl2tD8azCMw Wr+/bbJBAjZUVIsmb+utOvvImfmzTD5JcwB6GcfoWU0k9hRMoirrQumLzoxg== DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d= messagingengine.com; h=cc:content-type:date:date:feedback-id :feedback-id:from:from:in-reply-to:in-reply-to:message-id :mime-version:references:reply-to:sender:subject:subject:to:to :x-me-proxy:x-me-proxy:x-me-sender:x-me-sender:x-sasl-enc; s= fm3; t=1665958913; x=1666045313; bh=rEDhLvUrM8wofSeTARl6W0jXDeHV DxLIUCYfuv2y/cQ=; b=H6M4JQ7lV/bmdpx7nQEZsPRyc6b3LYmUonEzBnfphcXm zVxL2RwRBNLWmjWLDNyPNQiN61UpXz0Q9ZIaiHPfBOSzqcdJ18QN0iXCQ8domLXI lKkIz6IsJBrLaNXTg8UIdlLGFCxbU8gXC00vsLuHahzkyJBcTTOJFpFQtw3+TpJx 3MyaXkXvrW/LVU64azQinAL9n2qzNZMDDsg3YRHeTTctq3QAeIxL6OSSunkzlEGB AP4njnsiGqSljWixPjuZ39EQqIi/26pdFWC9Xc8afBFxcweK1eU7jWZL2Trq8I5f Imsl8byYIU8Ts7ApO97MFqBUIYcZaAeiqnIH3ZjEFQ== X-ME-Sender: X-ME-Proxy-Cause: gggruggvucftvghtrhhoucdtuddrgedvfedrfeekkedguddtucetufdoteggodetrfdotf fvucfrrhhofhhilhgvmecuhfgrshhtofgrihhlpdfqfgfvpdfurfetoffkrfgpnffqhgen uceurghilhhouhhtmecufedttdenucenucfjughrpefofgggkfgjfhffhffvufgtsehttd ertderredtnecuhfhrohhmpehvohhiugcuoehvohhiugesfhdqmhdrfhhmqeenucggtffr rghtthgvrhhnpeeitedvueehtdehtddvhfeuhfevhedvieelvdeiffehveelheegfedule ejudekvdenucevlhhushhtvghrufhiiigvpedtnecurfgrrhgrmhepmhgrihhlfhhrohhm pehvohhiugesfhdqmhdrfhhm X-ME-Proxy: Feedback-ID: i2541463c:Fastmail Received: by mailuser.nyi.internal (Postfix, from userid 501) id 2D5612A20079; Sun, 16 Oct 2022 18:21:53 -0400 (EDT) X-Mailer: MessagingEngine.com Webmail Interface User-Agent: Cyrus-JMAP/3.7.0-alpha0-1047-g9e4af4ada4-fm-20221005.001-g9e4af4ad List-Id: Filesystems List-Archive: https://lists.freebsd.org/archives/freebsd-fs List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-fs@freebsd.org Mime-Version: 1.0 Message-Id: <1ad018e7-a6c8-4306-b5b5-339631ad80ee@app.fastmail.com> In-Reply-To: <738D20C3-2F31-4869-B318-F1B30CDE3764@yahoo.com> References: <738D20C3-2F31-4869-B318-F1B30CDE3764.ref@yahoo.com> <738D20C3-2F31-4869-B318-F1B30CDE3764@yahoo.com> Date: Sun, 16 Oct 2022 22:20:41 +0000 From: void To: freebsd-fs Subject: Re: zfs with operations like rm -rf takes a very long time recently Content-Type: text/plain X-Rspamd-Queue-Id: 4MrF3Q6RlFz3Ych X-Spamd-Bar: ---- Authentication-Results: mx1.freebsd.org; dkim=pass header.d=f-m.fm header.s=fm3 header.b=jYTV6Juv; dkim=pass header.d=messagingengine.com header.s=fm3 header.b=H6M4JQ7l; dmarc=pass (policy=none) header.from=f-m.fm; spf=pass (mx1.freebsd.org: domain of void@f-m.fm designates 64.147.123.19 as permitted sender) smtp.mailfrom=void@f-m.fm X-Spamd-Result: default: False [-4.58 / 15.00]; DWL_DNSWL_LOW(-1.00)[messagingengine.com:dkim]; NEURAL_HAM_LONG(-1.00)[-1.000]; NEURAL_HAM_MEDIUM(-1.00)[-1.000]; NEURAL_HAM_SHORT(-0.99)[-0.994]; DMARC_POLICY_ALLOW(-0.50)[f-m.fm,none]; MV_CASE(0.50)[]; R_SPF_ALLOW(-0.20)[+ip4:64.147.123.19:c]; R_DKIM_ALLOW(-0.20)[f-m.fm:s=fm3,messagingengine.com:s=fm3]; RCVD_IN_DNSWL_LOW(-0.10)[64.147.123.19:from]; MIME_GOOD(-0.10)[text/plain]; XM_UA_NO_VERSION(0.01)[]; TO_MATCH_ENVRCPT_ALL(0.00)[]; FROM_HAS_DN(0.00)[]; RCPT_COUNT_ONE(0.00)[1]; PREVIOUSLY_DELIVERED(0.00)[freebsd-fs@freebsd.org]; ARC_NA(0.00)[]; ASN(0.00)[asn:29838, ipnet:64.147.123.0/24, country:US]; FREEMAIL_ENVFROM(0.00)[f-m.fm]; RCVD_COUNT_THREE(0.00)[4]; FREEMAIL_FROM(0.00)[f-m.fm]; RCVD_TLS_LAST(0.00)[]; TO_DN_ALL(0.00)[]; FROM_EQ_ENVFROM(0.00)[]; DKIM_TRACE(0.00)[f-m.fm:+,messagingengine.com:+]; MIME_TRACE(0.00)[0:+]; MLMMJ_DEST(0.00)[freebsd-fs@freebsd.org] X-ThisMailContainsUnwantedMimeParts: N A few hrs ago I rebooted and ran zpool scrub just-in-case, and it completed without issue: # zpool status -v pool: zroot state: ONLINE scan: scrub repaired 0B in 01:41:20 with 0 errors on Sun Oct 16 19:47:00 2022 config: NAME STATE READ WRITE CKSUM zroot ONLINE 0 0 0 da0p3 ONLINE 0 0 0 errors: No known data errors On Sun, 16 Oct 2022, at 18:24, Mark Millard wrote: > One thing we do not have is a set of before-the-problem data > to compare against. It is hard to tell specifically what time > frames have changed. > > I'd guess that each/any of the following could produce interesting > background information during the problem: > > # zpool iostat -w > # zpool iostat -l > # zpool iostat -r > # zpool iostat -q Ok here's output when it was trying to du -sh /usr/ports. This also has the following sysctl set : vfs.zfs.per_txg_dirty_frees_percent=5 (it took this long to complete: # date && du -sh /usr/ports && date Sun Oct 16 23:06:24 BST 2022 8.7G /usr/ports Sun Oct 16 23:14:25 BST 2022) # zpool iostat -w zroot total_wait disk_wait syncq_wait asyncq_wait latency read write read write read write read write scrub trim rebuild ---------- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- 1ns 0 0 0 0 0 0 0 0 0 0 0 3ns 0 0 0 0 0 0 0 0 0 0 0 7ns 0 0 0 0 0 0 0 0 0 0 0 15ns 0 0 0 0 0 0 0 0 0 0 0 31ns 0 0 0 0 0 0 0 0 0 0 0 63ns 0 0 0 0 0 0 0 0 0 0 0 127ns 0 0 0 0 0 0 0 0 0 0 0 255ns 0 0 0 0 0 0 0 0 0 0 0 511ns 0 0 0 0 3 2.53K 0 7 0 0 0 1us 0 0 0 0 19.0K 6.38K 760 702 72 0 0 2us 0 0 0 0 12.5K 1.95K 1014 4.24K 520 0 0 4us 0 0 0 0 6.17K 7.76K 394 8.10K 224 0 0 8us 0 0 0 0 4.37K 8.12K 141 11.2K 167 0 0 16us 0 0 0 0 1.28K 302 57 2.17K 12 0 0 32us 0 0 0 0 68 34 3 380 1 0 0 65us 0 0 0 0 3 2 5 584 0 0 0 131us 0 0 0 0 7 1 10 1.41K 5 0 0 262us 0 0 0 0 4 1 96 4.26K 8 0 0 524us 12.5K 18.5K 13.0K 18.7K 5 0 145 14.1K 648 0 0 1ms 1.46K 23.6K 2.36K 161K 2 0 116 18.3K 259 0 0 2ms 881 42.5K 9.83K 60.9K 5 0 30 29.8K 256 0 0 4ms 1.05K 50.4K 59.6K 9.75K 22 0 55 44.3K 235 0 0 8ms 3.67K 61.0K 154K 4.47K 79 0 149 47.5K 16.2K 0 0 16ms 11.4K 21.5K 290K 6.40K 234 0 303 14.2K 77.8K 0 0 33ms 19.6K 17.9K 328K 7.10K 455 0 221 13.7K 40.7K 0 0 67ms 147K 13.6K 72.7K 2.23K 899 0 218 11.4K 42.2K 0 0 134ms 65.3K 12.8K 7.88K 1.98K 1.72K 0 368 10.7K 44.7K 0 0 268ms 70.9K 10.3K 4.42K 1.36K 2.60K 0 304 8.41K 64.2K 0 0 536ms 105K 1.73K 171 105 1.86K 0 170 1.42K 101K 0 0 1s 163K 221 11 0 211 0 117 182 161K 0 0 2s 160K 0 1 0 0 0 47 0 158K 0 0 4s 109K 0 0 0 0 0 0 0 108K 0 0 8s 60.6K 0 0 0 0 0 0 0 60.1K 0 0 17s 8.35K 0 0 0 0 0 0 0 8.29K 0 0 34s 1.56K 0 0 0 0 0 0 0 1.56K 0 0 68s 0 0 0 0 0 0 0 0 0 0 0 137s 0 0 0 0 0 0 0 0 0 0 0 --------------------------------------------------------------------------------------- # zpool iostat -l capacity operations bandwidth total_wait disk_wait syncq_wait asyncq_wait scrub trim rebuild pool alloc free read write read write read write read write read write read write wait wait wait ---------- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- zroot 154G 758G 51 15 9.07M 448K 1s 22ms 19ms 4ms 32ms 3us 75ms 20ms 1s - - # zpool iostat -r zroot sync_read sync_write async_read async_write scrub trim rebuild req_size ind agg ind agg ind agg ind agg ind agg ind agg ind agg ---------- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- 512 20.4K 0 0 0 0 0 283 0 7.64K 0 0 0 0 0 1K 3.62K 0 0 0 0 0 1.23K 0 14.2K 0 0 0 0 0 2K 1.47K 0 0 0 0 0 5.10K 0 22.3K 0 0 0 0 0 4K 22.6K 0 11.9K 0 1.22K 0 79.1K 0 353K 0 0 0 0 0 8K 3.22K 14 13.3K 0 2.44K 107 37.3K 29.6K 19.1K 73.2K 0 0 0 0 16K 100 68 734 0 45 389 2.58K 28.3K 5.77K 87.1K 0 0 0 0 32K 274 48 623 0 29 248 18.9K 14.1K 4.25K 68.3K 0 0 0 0 64K 105 18 482 0 0 90 1.37K 15.6K 2.32K 37.7K 0 0 0 0 128K 0 5 60 0 0 37 0 9.20K 3.18K 23.1K 0 0 0 0 256K 0 1 0 0 0 18 0 3.47K 0 17.5K 0 0 0 0 512K 0 1 0 0 0 6 0 953 0 23.1K 0 0 0 0 1M 0 0 0 0 0 0 0 10 0 125K 0 0 0 0 2M 0 0 0 0 0 0 0 0 0 0 0 0 0 0 4M 0 0 0 0 0 0 0 0 0 0 0 0 0 0 8M 0 0 0 0 0 0 0 0 0 0 0 0 0 0 16M 0 0 0 0 0 0 0 0 0 0 0 0 0 0 ------------------------------------------------------------------------------------------------------------ # zpool iostat -q capacity operations bandwidth syncq_read syncq_write asyncq_read asyncq_write scrubq_read trimq_write rebuildq_write pool alloc free read write read write pend activ pend activ pend activ pend activ pend activ pend activ pend activ ---------- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- zroot 154G 758G 51 15 9.06M 448K 0 1 0 0 0 0 0 0 0 0 0 0 0 0