Skip site navigation (1)Skip section navigation (2)
Date:      Wed, 22 Jul 2020 20:26:56 +0700
From:      Eugene Grosbein <eugen@grosbein.net>
To:        mike tancsa <mike@sentex.net>, Ronald Klop <ronald-lists@klop.ws>, FreeBSD-STABLE Mailing List <freebsd-stable@freebsd.org>
Subject:   Re: zfs meta data slowness
Message-ID:  <097a63f1-3b25-3916-cdb9-1d4cf0d088fd@grosbein.net>
In-Reply-To: <2267c96f-b988-df1e-887b-77dc9b2a3e32@sentex.net>
References:  <b6d670e6-6e35-a1f7-7daf-76b458f26e30@sentex.net> <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>

next in thread | previous in thread | raw e-mail | index | archive | help
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.




Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?097a63f1-3b25-3916-cdb9-1d4cf0d088fd>