From nobody Fri Oct 27 11:45:24 2023 X-Original-To: freebsd-stable@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 4SH17c1vmZz4y93g for ; Fri, 27 Oct 2023 11:45:32 +0000 (UTC) (envelope-from SRS0=D2w5=GJ=klop.ws=ronald-lists@realworks.nl) Received: from smtp-relay-int.realworks.nl (smtp-relay-int.realworks.nl [194.109.157.24]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 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 4SH17b4LTLz4J0h for ; Fri, 27 Oct 2023 11:45:31 +0000 (UTC) (envelope-from SRS0=D2w5=GJ=klop.ws=ronald-lists@realworks.nl) Authentication-Results: mx1.freebsd.org; none Date: Fri, 27 Oct 2023 13:45:24 +0200 (CEST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=klop.ws; s=rw2; t=1698407124; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: in-reply-to:in-reply-to:references:references; bh=oiCDRdZItvUqUOXwgxfyYalsx2t7TKAzuZYA7S6WGGM=; b=zvsvGfpa3aITFsIhDBvX8qznT0+BhMuYjVLxZgoDXBm2L6SggnWk7hVTM1YEtB2gHAVJhu 1aBkl87iAZ9DpkPDLE061ycLohnTmvQnYNcmfcuJSb8Q3Z0hn2hEDoexRGMMoxe2x3fr0k v9PdNGldF0Y5oze/SoHOgaRZbI6MOU9QdkAnV2XykmnfNHp2Ijmlgk8VNFUCkYMcwAOsco WJsE8YmDYk1QtEHWpUcfCA7QTc9Nrkbhi2MtQis4ECp9rtkGNSAP2QmawuzynkEc4xhyhP 24N3dpyMjVQD+H/Zw2pKu/wBQD9Zn77qcdj+mie2lyhkjNPl8haHONbe5KqFdg== From: Ronald Klop To: void Cc: freebsd-stable@freebsd.org Message-ID: <1122335317.4913.1698407124469@localhost> In-Reply-To: References: Subject: Re: periodic daily takes a very long time to run (14-stable) List-Id: Production branch of FreeBSD source code List-Archive: https://lists.freebsd.org/archives/freebsd-stable List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-stable@freebsd.org X-BeenThere: freebsd-stable@freebsd.org MIME-Version: 1.0 Content-Type: multipart/alternative; boundary="----=_Part_4912_1359293768.1698407124396" X-Mailer: Realworks (677.7) Importance: Normal X-Priority: 3 (Normal) X-Spamd-Bar: ---- X-Rspamd-Pre-Result: action=no action; module=replies; Message is reply to one we originated X-Spamd-Result: default: False [-4.00 / 15.00]; REPLY(-4.00)[]; ASN(0.00)[asn:3265, ipnet:194.109.0.0/16, country:NL] X-Rspamd-Queue-Id: 4SH17b4LTLz4J0h ------=_Part_4912_1359293768.1698407124396 Content-Type: text/plain; charset=us-ascii; format=flowed Content-Transfer-Encoding: 7bit Van: void Datum: vrijdag, 27 oktober 2023 12:15 Aan: freebsd-stable@freebsd.org Onderwerp: periodic daily takes a very long time to run (14-stable) > > Hello list, > > I'm asking this in order to determine whether I've got something misconfigured or > maybe my expectations need recalibrating, or maybe both. > > context is rpi4b with 8GB and usb3-connected 1tb zfs hard disk. > /etc/daily.local has been moved out of the way to try to fix the issue. > > When periodic daily runs, it seems to take a long time. It's running now and has > been running for overan hour so far. > > top shows > PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU COMMAND > 21649 root 1 20 0 18M 6668K zio->i 1 0:40 0.53% find > > There's plenty of resources > > 93 processes: 1 running, 92 sleeping > CPU: 0.1% user, 0.0% nice, 0.5% system, 0.0% interrupt, 99.4% idle > Mem: 202M Active, 688M Inact, 69M Laundry, 3079M Wired, 216K Buf, 3780M Free > ARC: 975M Total, 552M MFU, 244M MRU, 808K Anon, 21M Header, 158M Other > 229M Compressed, 905M Uncompressed, 3.95:1 Ratio > Swap: 12G Total, 12G Free > > but the 'find' thing does heavy disk i/o and everything else reading from or writing to disk slows to a crawl. > > # cat /etc/periodic.conf > daily_status_smart_devices="da0" > daily_status_include_submit_mailq="NO" > daily_clean_hoststat_enable="NO" > daily_queuerun_enable="NO" > daily_submit_queuerun="NO" > daily_scrub_zfs_enable="YES" > daily_scrub_zfs_pools="" > daily_scrub_zfs_default_threshold="7" > daily_status_ntpd_enable="YES" > daily_clean_disks_enable="YES" > > zpool last scrubbed on the 21st; it's not happening right now > > there's the following in /etc/sysctl.conf relevant to the context: > > vfs.zfs.min_auto_ashift=12 > # > # filesystem > vm.pageout_oom_seq=120 > vm.pfault_oom_attempts=-1 > vm.pageout_update_period=0 > # vfs.zfs.resilver_min_time_ms=5000 > vfs.zfs.arc.min=536870912 > vfs.zfs.arc_max=1073741824 > > The OOM settings are there for poudriere. > > # zdb | grep ashift > ashift: 12 > > # ps xx | grep periodic > 68824 11 S+ 0:00.00 grep periodic > 16115 14 I+ 0:00.00 /bin/sh - /usr/sbin/periodic daily > 17425 14 I+ 0:00.00 lockf -s -t 0 /var/run/periodic.daily.lock /bin/sh /usr/sbin/periodic LOCKED daily > 17747 14 I+ 0:00.01 /bin/sh /usr/sbin/periodic LOCKED daily <=== why are there two of these? > 19460 14 I+ 0:00.00 /bin/sh /usr/sbin/periodic LOCKED daily <=== > 19921 14 I+ 0:00.00 /bin/sh /etc/periodic/daily/100.clean-disks <=== also here > 21312 14 I+ 0:00.00 /bin/sh /etc/periodic/daily/100.clean-disks <=== > > I'm not sure if it's relevant, but the disk, when the zroot/zfs was initialised, was set > to enforce 4k blocks, geli-encrypted swap, geli-encrypted fs. Because it's an rpi4, there's > no aes-ni equivalent hardware. But the slowdown doesn't show much in other areas, only a couple, > like this problem and when git updates src or ports. smartctl shows no remapped or pending blocks. > > What else can I do to debug the issue? > -- > > > > Hi, Can you run "gstat" or "iostat -x -d 1" to see how busy your disk is? And how much bandwidth is uses. The output of "zpool status", "zpool list" and "zfs list" can also be interesting. ZFS is known to become slow when the zpool is full almost full. Regards, Ronald. ------=_Part_4912_1359293768.1698407124396 Content-Type: text/html; charset=us-ascii Content-Transfer-Encoding: 7bit

Van: void <void@f-m.fm>
Datum: vrijdag, 27 oktober 2023 12:15
Aan: freebsd-stable@freebsd.org
Onderwerp: periodic daily takes a very long time to run (14-stable)

Hello list,

I'm asking this in order to determine whether I've got something misconfigured or
maybe my expectations need recalibrating, or maybe both.

context is rpi4b with 8GB and usb3-connected 1tb zfs hard disk.
/etc/daily.local has been moved out of the way to try to fix the issue.

When periodic daily runs, it seems to take a long time. It's running now and has
been running for overan hour so far.

top shows
   PID   USERNAME    THR  PRI   NICE SIZE RES   STATE    C   TIME    WCPU COMMAND
   21649 root          1  20    0    18M  6668K zio->i   1   0:40   0.53% find

There's plenty of resources

93 processes:  1 running, 92 sleeping
CPU:  0.1% user,  0.0% nice,  0.5% system,  0.0% interrupt, 99.4% idle
Mem: 202M Active, 688M Inact, 69M Laundry, 3079M Wired, 216K Buf, 3780M Free
ARC: 975M Total, 552M MFU, 244M MRU, 808K Anon, 21M Header, 158M Other
      229M Compressed, 905M Uncompressed, 3.95:1 Ratio
      Swap: 12G Total, 12G Free

but the 'find' thing does heavy disk i/o and everything else reading from or writing to disk slows to a crawl.

# cat /etc/periodic.conf
daily_status_smart_devices="da0"
daily_status_include_submit_mailq="NO"
daily_clean_hoststat_enable="NO"
daily_queuerun_enable="NO"
daily_submit_queuerun="NO"
daily_scrub_zfs_enable="YES"
daily_scrub_zfs_pools=""
daily_scrub_zfs_default_threshold="7"
daily_status_ntpd_enable="YES"
daily_clean_disks_enable="YES"

zpool last scrubbed on the 21st; it's not happening right now

there's the following in /etc/sysctl.conf relevant to the context:

vfs.zfs.min_auto_ashift=12
#
# filesystem
vm.pageout_oom_seq=120
vm.pfault_oom_attempts=-1
vm.pageout_update_period=0
# vfs.zfs.resilver_min_time_ms=5000
vfs.zfs.arc.min=536870912
vfs.zfs.arc_max=1073741824

The OOM settings are there for poudriere.

# zdb | grep ashift
             ashift: 12            

# ps xx | grep periodic
68824 11  S+      0:00.00 grep periodic
16115 14  I+      0:00.00 /bin/sh - /usr/sbin/periodic daily
17425 14  I+      0:00.00 lockf -s -t 0 /var/run/periodic.daily.lock /bin/sh /usr/sbin/periodic LOCKED daily
17747 14  I+      0:00.01 /bin/sh /usr/sbin/periodic LOCKED daily  <=== why are there two of these?
19460 14  I+      0:00.00 /bin/sh /usr/sbin/periodic LOCKED daily  <===
19921 14  I+      0:00.00 /bin/sh /etc/periodic/daily/100.clean-disks <=== also here
21312 14  I+      0:00.00 /bin/sh /etc/periodic/daily/100.clean-disks <===

I'm not sure if it's relevant, but the disk, when the zroot/zfs was initialised, was set
to enforce 4k blocks, geli-encrypted swap, geli-encrypted fs. Because it's an rpi4, there's
no aes-ni equivalent hardware. But the slowdown doesn't show much in other areas, only a couple,
like this problem and when git updates src or ports. smartctl shows no remapped or pending blocks.

What else can I do to debug the issue?
-- 
 


Hi,

Can you run "gstat" or "iostat -x -d 1" to see how busy your disk is? And how much bandwidth is uses.

The output of "zpool status", "zpool list" and "zfs list" can also be interesting.

ZFS is known to become slow when the zpool is full almost full.

Regards,
Ronald.
  ------=_Part_4912_1359293768.1698407124396--