From owner-freebsd-stable@freebsd.org Wed Jul 22 13:27:19 2020 Return-Path: Delivered-To: freebsd-stable@mailman.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.nyi.freebsd.org (Postfix) with ESMTP id 0A5E837C869 for ; Wed, 22 Jul 2020 13:27:19 +0000 (UTC) (envelope-from eugen@grosbein.net) Received: from hz.grosbein.net (hz.grosbein.net [IPv6:2a01:4f8:c2c:26d8::2]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client CN "hz.grosbein.net", Issuer "hz.grosbein.net" (not verified)) by mx1.freebsd.org (Postfix) with ESMTPS id 4BBbqB0rhbz4BdM for ; Wed, 22 Jul 2020 13:27:17 +0000 (UTC) (envelope-from eugen@grosbein.net) Received: from eg.sd.rdtc.ru (eg.sd.rdtc.ru [IPv6:2a03:3100:c:13:0:0:0:5]) by hz.grosbein.net (8.15.2/8.15.2) with ESMTPS id 06MDR2gu030258 (version=TLSv1.2 cipher=DHE-RSA-AES256-GCM-SHA384 bits=256 verify=NOT); Wed, 22 Jul 2020 13:27:03 GMT (envelope-from eugen@grosbein.net) X-Envelope-From: eugen@grosbein.net X-Envelope-To: mike@sentex.net Received: from [10.58.0.10] (dadvw [10.58.0.10]) by eg.sd.rdtc.ru (8.15.2/8.15.2) with ESMTPS id 06MDR5o3053661 (version=TLSv1.2 cipher=DHE-RSA-AES128-SHA bits=128 verify=NOT); Wed, 22 Jul 2020 20:27:05 +0700 (+07) (envelope-from eugen@grosbein.net) Subject: Re: zfs meta data slowness To: mike tancsa , Ronald Klop , FreeBSD-STABLE Mailing List References: <1949194763.1.1595250243575@localhost> <975657af-ccac-bbd1-e22b-86270c624226@sentex.net> <9ddce60a-9d91-fa69-0e11-54342cb67890@grosbein.net> <2267c96f-b988-df1e-887b-77dc9b2a3e32@sentex.net> From: Eugene Grosbein Message-ID: <097a63f1-3b25-3916-cdb9-1d4cf0d088fd@grosbein.net> Date: Wed, 22 Jul 2020 20:26:56 +0700 User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:45.0) Gecko/20100101 Thunderbird/45.8.0 MIME-Version: 1.0 In-Reply-To: <2267c96f-b988-df1e-887b-77dc9b2a3e32@sentex.net> Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-Spam-Status: No, score=0.3 required=5.0 tests=BAYES_00,LOCAL_FROM, NICE_REPLY_A,SPF_HELO_NONE,SPF_PASS autolearn=no autolearn_force=no version=3.4.2 X-Spam-Report: * -2.3 BAYES_00 BODY: Bayes spam probability is 0 to 1% * [score: 0.0000] * 0.0 SPF_HELO_NONE SPF: HELO does not publish an SPF Record * -0.0 SPF_PASS SPF: sender matches SPF record * 2.6 LOCAL_FROM From my domains * -0.0 NICE_REPLY_A Looks like a legit reply (A) X-Spam-Checker-Version: SpamAssassin 3.4.2 (2018-09-13) on hz.grosbein.net X-Rspamd-Queue-Id: 4BBbqB0rhbz4BdM X-Spamd-Bar: - Authentication-Results: mx1.freebsd.org; dkim=none; dmarc=none; spf=permerror (mx1.freebsd.org: domain of eugen@grosbein.net uses mechanism not recognized by this client) smtp.mailfrom=eugen@grosbein.net X-Spamd-Result: default: False [-1.74 / 15.00]; ARC_NA(0.00)[]; NEURAL_HAM_MEDIUM(-0.62)[-0.616]; FROM_HAS_DN(0.00)[]; RCPT_COUNT_THREE(0.00)[3]; NEURAL_HAM_LONG(-0.80)[-0.801]; MIME_GOOD(-0.10)[text/plain]; DMARC_NA(0.00)[grosbein.net]; RCVD_COUNT_THREE(0.00)[3]; TO_MATCH_ENVRCPT_SOME(0.00)[]; TO_DN_ALL(0.00)[]; R_SPF_PERMFAIL(0.00)[empty SPF record]; NEURAL_HAM_SHORT(-0.23)[-0.226]; FROM_EQ_ENVFROM(0.00)[]; R_DKIM_NA(0.00)[]; MIME_TRACE(0.00)[0:+]; ASN(0.00)[asn:24940, ipnet:2a01:4f8::/29, country:DE]; RCVD_TLS_ALL(0.00)[]; MID_RHS_MATCH_FROM(0.00)[] X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.33 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 22 Jul 2020 13:27:19 -0000 22.07.2020 20:02, mike tancsa wrote: > > On 7/22/2020 1:29 AM, Eugene Grosbein wrote: >> 22.07.2020 2:37, mike tancsa wrote: >> >>>> Something else special about the setup. >>>> output of "top -b" >>>> >>> ports are right now being built in a VM, but the problem (zrepl hanging) >>> and zfs list -t snapshots taking forever happens regardless >>> >>> PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU >>> COMMAND >>> 4439 root 12 40 20 6167M 5762M kqread 3 535:13 200.00% bhyve >>> 98783 root 2 21 0 16M 5136K hdr->b 4 0:01 1.95% zfs >>> 76489 root 21 23 0 738M 54M uwait 1 2:18 0.88% zrepl >>> 98784 root 1 21 0 13M 3832K piperd 3 0:01 0.59% zfs >>> 99563 root 1 20 0 13M 4136K zio->i 4 0:00 0.39% zfs >> You need top -SHPI > > last pid: 66981; load averages: 3.44, 3.25, 3.34 up 1+22:49:34 > 08:58:06 > 2056 threads: 12 running, 1988 sleeping, 3 zombie, 53 waiting > CPU 0: 7.7% user, 0.1% nice, 15.0% system, 0.7% interrupt, 76.5% idle > CPU 1: 9.9% user, 0.1% nice, 16.6% system, 0.1% interrupt, 73.2% idle > CPU 2: 10.0% user, 0.1% nice, 17.5% system, 0.4% interrupt, 71.9% idle > CPU 3: 10.3% user, 0.1% nice, 21.2% system, 0.1% interrupt, 68.2% idle > CPU 4: 9.7% user, 0.1% nice, 15.6% system, 0.4% interrupt, 74.3% idle > CPU 5: 10.2% user, 0.1% nice, 21.3% system, 0.1% interrupt, 68.3% idle > CPU 6: 9.7% user, 0.1% nice, 16.6% system, 0.5% interrupt, 73.1% idle > CPU 7: 10.1% user, 0.1% nice, 21.3% system, 0.1% interrupt, 68.4% idle > Mem: 4236M Active, 19G Inact, 283M Laundry, 37G Wired, 3248K Buf, 1667M Free > ARC: 25G Total, 9939M MFU, 12G MRU, 397M Anon, 573M Header, 2143M Other > 20G Compressed, 29G Uncompressed, 1.43:1 Ratio > Swap: 20G Total, 20G Free > > PID USERNAME PRI NICE SIZE RES STATE C TIME WCPU COMMAND > 4439 root 123 20 6167M 5856M CPU2 2 20.2H 100.00% > bhyve{vcpu 0} > 4439 root 122 20 6167M 5856M CPU3 3 20.2H 99.17% > bhyve{vcpu 1} > 11 root 155 ki31 0B 128K CPU0 0 35.9H 65.38% > idle{idle: cpu0} > 11 root 155 ki31 0B 128K CPU4 4 34.8H 63.38% > idle{idle: cpu4} > 66956 root 90 0 61M 54M CPU5 5 0:09 62.70% zfs > 11 root 155 ki31 0B 128K CPU6 6 34.3H 58.06% > idle{idle: cpu6} > 11 root 155 ki31 0B 128K RUN 2 33.7H 54.49% > idle{idle: cpu2} > 11 root 155 ki31 0B 128K RUN 1 34.3H 53.76% > idle{idle: cpu1} > 11 root 155 ki31 0B 128K RUN 3 32.0H 53.47% > idle{idle: cpu3} > 11 root 155 ki31 0B 128K CPU7 7 32.0H 50.68% > idle{idle: cpu7} > 11 root 155 ki31 0B 128K RUN 5 32.0H 48.29% > idle{idle: cpu5} > 56 root -12 - 0B 5168K - 1 5:49 9.67% > zpool-zbackup2{zio_write_issue_3} > 56 root -12 - 0B 5168K - 3 5:48 9.57% > zpool-zbackup2{zio_write_issue_5} > 56 root -12 - 0B 5168K - 4 5:48 9.47% > zpool-zbackup2{zio_write_issue_4} > 56 root -12 - 0B 5168K - 7 5:48 9.47% > zpool-zbackup2{zio_write_issue_2} > 56 root -12 - 0B 5168K - 0 5:49 9.38% > zpool-zbackup2{zio_write_issue_1} > 56 root -12 - 0B 5168K - 1 5:48 9.38% > zpool-zbackup2{zio_write_issue_0} > 63392 root 23 0 729M 32M uwait 0 0:01 4.20% > zrepl{zrepl} It's hard to read due to wrapping plus, it is truncated. Maybe additional flag -d3 or similar will help, combined with dedirection < /dev/null > top.out so it won't use size of your terminal to wrap/truncate output. Also, make sure you invoke top while "zfs" command is running. Also, procstat -kk for pid of "zfs" command would be useful (but may occur pretty long). I suppose it blocks waiting for some kernel lock and procstat would show details.