From owner-freebsd-stable@freebsd.org Fri Mar 5 21:11:15 2021 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 F2CEC567FE8 for ; Fri, 5 Mar 2021 21:11:15 +0000 (UTC) (envelope-from marklmi@yahoo.com) Received: from sonic310-24.consmr.mail.ne1.yahoo.com (sonic310-24.consmr.mail.ne1.yahoo.com [66.163.186.205]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 4DsgQB620Zz3l6v for ; Fri, 5 Mar 2021 21:11:14 +0000 (UTC) (envelope-from marklmi@yahoo.com) X-SONIC-DKIM-SIGN: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s2048; t=1614978673; bh=gYHh6/BHXvbpImEac8zci96/rikli8Xof7pTkAPt3rz=; h=X-Sonic-MF:From:Subject:Date:To:From:Subject; b=NVdAlxKnXyizZGAZFZrwH68YGBDCAkncE7yIfiWdNvMr6fHYvr1zMQOjWf8MLlCTJQ9XvYS1KQyyrtJx/3F7L3U5UiX1EoMBdy3LrZU3XDRbWR18Cc0rci1K/KQzWbsyDKs9kMOxA0C9/1vepKbxf6fmNIOVlHokpab00BMHf1UYtqYK3s8yIA/qaWy7bfTi22P1Z3iHX7011xajoxRx/qRCC2cnO6z7UeThT74CTdFlslJZrgkxPUnLB77g0FzSzexc8ZdZ1ze81CqXVtYf4olltlmRYpW8QPN7R4yMazCVMEEWbo928rc0MPSho9iyFmuYIs2uyb0Xvtario8kqw== X-YMail-OSG: xt_JBIcVM1mmfAu3lbkJMGIhFi16YZE2HKCSov_5VRfS1Z7FAHJwM9oN1Nob_.n Sb65Vh.j6nUoqgiE1fgCIv3udEKUlbtLOnXwbRwCXc9MAUPaL2bNqgeduzdo5QZFPPDpmR0Lx1be hlxNhiWXaIwbpC4NJhYGimYQWz4dz6KAY.Ow4zkSXPQ2VwmAvHyR9WgaZUKUjMXI4jNKAYHZvBaG xW0IogWNnIvDR9OqkAbSA9TUa5K4L3inNYETR855ffs_lmZnArrpgo1LBq6dxzC15ERdWqyEnCST R5lsqwmVNTH8DoaE50zSlZbcbzOJr8pcVw5oaH4km.hwxKWGHD4GdiqE2JsJAVICd.l4kq5snjzf doKsJ5gW6NtGI_DK.rPkMI10wt0zFrgU9kGeXkrq1lkLbcmptFLk3wA4JYuHouBFfmb8OTkoB4SL 3KWcEPVfzIyHdJ9OPOH6kgQRoxT0O6eeIjlZex2gvYxEsIBovjxVE7vl6AHslRzfzj.ed7LfJQkd XN7X.GyfRyueUtEy_NjFt0Lqs7oR1VcNXFgluDFTDwlqVpzOMA_y0XI5kT8.sNnBIfdinlipWutf FrWnecWGk.nD01a07TwDV87tvR7BMl58QZ8jm4n.bs7xfGmr0v8zWUaiMhTYvc0hIkQ3ouW9gHLn Ff5OrDFIiCNwBgp17fnutOH2xbLjhZh_NVCdtTXLMxtZjxvOwUxkca1lGsCQhpBS30b4EplrxfR_ kBbZm0C0v69wosEIdsZxDpfHfauxR3Y_ukR86DeoqQ8KZQLHuFzprUldNcGckoe5bY5RJNLog_Jr YMRfdyUyDbI9W00RwTmz8RR5wZH_BA17e4qTXTs.rGFnXNYPty33clESm_N8MooL2LziN23dqZ_V t_oMUxIkSdOtEpopTLs2hk9JROUyScWVdPa9p7I0_mLjY7Drecxbv.zrJ02FVNaq7t5f0tkYA_8h hJbzcSwdRVrfJWo_.wVHeg5_rWWo6B3c.uFV6T6l9Zvlh_gwKpptSa4K8HxBm6PPQdzJHs3TaI40 YJlXR7PR4bmhnP2qkGzdSNGyuhIiHcb8aFGKJDTkzar8aEPiGGevLo1oGBDhE3AHNW_jUq.OmW7R RDHE2EzkI4axOGuavjIGdhJC.GumVgJA8hy2U4b8sQDe_6gMOMSE2FsYGDOI.TWQuJqaI6m43Q2m ffQVi2DxwqOjGW6K4PF_3qZNn1z9FlhOFu37FhrDfTh0A8NQaB1FEIenJvJY1Bb98fjiQJP4pjiT FokGsGrNlvggKso0UUaKcXbkObiOo2hYP7IAIXCkp0TKglkY0yNrsjKUYOay6XWRuOjQT9H1Llzu 0scsALL4p4_owYDqtbwcd0TIHLWyLlheX4Q54mdWlEx64JTmC_r9eJAZLeRRZCk2ufgv1.Qr7B74 2wLAQdcg9tF5Zz4TpUpNIwk_xmCU1cOhLy0H8PmnUDl7ELVJz2GFwqgvgskhTOvzM6ptmuFrhZWF 1aMJqhVNXqHX7qPxd177dgbGr.Gf2bU.81lXFYmX28uEyWm70gJ..7iqiAKuk7A5l8JUMrix1kHw QLcghrrizxwKuWWzbvRjK2VNzD.JBAQxl8XFjV5I4yvVh0osFWZQ6_pJ5X8PP15sX4kqeHzQuBOL s206nm9nnFblmQ21kdA7XN3DOpdhm8Q9CeMi01M4Q8JqWxTdAagLbVgYdFTWE2Nbo3xvRW69jjY9 9xh2Hr2E2A1cTPFGah9pO5TyDunpdOfzQbrAPgag5h61q62g4HrtAgjfV3ItqgkoQSKN_UO6fpaV YNDnaBxkHV6i0scJfZmXcVO5EscUvso_QT7iQJnTza0j7DkkwN0OOffwB47vsbwIcesibiuvMn6. 5RUB9iYEJZ6e0oTC.sIqyD4Wwz0YwBUEvm4JlReDHqzA9Iq1xxBbJ5NzRNqW6acAAIIcO5C9.pHW y8HRaYx8JJ_rsF7PEWeFCxF1kaQaCF75Hyf.YdfECAKKQG6hb6k2lvgkxqoJJRRTs2JDXQeRhgYH aE3N_iPIV7dL6r8gLtRAKxKXiBI_3VyiKA.spoRMqxgOOoUbC5LHzwhwTLjplJ9EnqfxKIzbjEwL Gm75f3VLhNOzGtG2HgX.ydifyJIhHhvTJeiE_4ljNZRIppnJLd7n4H5wcGmpdH6Nc80OcaKbO7GS oPdmij46Tb3qqHeIgTSmYgH5h9SCc8_9Sq_5pWqUc7CpuzrQhXSCEDkVEVsJaczSfWS3gaQ_5RNE ajwXE79TLitZnLMFKV8KvZpPGQ8H9ww95lt_b4Dm.rZIHTON4hl6o3T_Pgiitj68DOqsEBtn5ztp JkCN038SyPB6VIoQDfW35EZYgqCEPgcQ8sP5m5wikV6gjVxs3kkiJ2BId9ETaIpNOWTLw7ZTg4Mg q9Z_lY6OsSGQuwmXfQBzXR2lNTuv5_5R1gpgLiypSoVTnBntwXJiMhiazjyRQVv1OrQdveTnrSJw NqbYbI5JgHes9vFYwSoTNFg-- X-Sonic-MF: Received: from sonic.gate.mail.ne1.yahoo.com by sonic310.consmr.mail.ne1.yahoo.com with HTTP; Fri, 5 Mar 2021 21:11:13 +0000 Received: by kubenode509.mail-prod1.omega.gq1.yahoo.com (VZM Hermes SMTP Server) with ESMTPA ID 1c25e11fcd719636c3ba428ed9511956; Fri, 05 Mar 2021 21:11:07 +0000 (UTC) From: Mark Millard Content-Type: text/plain; charset=us-ascii Content-Transfer-Encoding: quoted-printable Mime-Version: 1.0 (Mac OS X Mail 14.0 \(3654.60.0.2.21\)) Subject: Re: Filesystem operations slower in 13.0 than 12.2 Date: Fri, 5 Mar 2021 13:11:06 -0800 References: To: chris@cretaforce.gr, freebsd-stable@freebsd.org In-Reply-To: Message-Id: <204B3B0C-E695-4CCF-90DE-14A841BA6180@yahoo.com> X-Mailer: Apple Mail (2.3654.60.0.2.21) X-Rspamd-Queue-Id: 4DsgQB620Zz3l6v X-Spamd-Bar: - X-Spamd-Result: default: False [-1.50 / 15.00]; FREEMAIL_FROM(0.00)[yahoo.com]; MV_CASE(0.50)[]; TO_DN_NONE(0.00)[]; R_SPF_ALLOW(-0.20)[+ptr:yahoo.com]; DKIM_TRACE(0.00)[yahoo.com:+]; RCPT_COUNT_TWO(0.00)[2]; DMARC_POLICY_ALLOW(-0.50)[yahoo.com,reject]; FROM_EQ_ENVFROM(0.00)[]; RCVD_TLS_LAST(0.00)[]; MIME_TRACE(0.00)[0:+]; FREEMAIL_ENVFROM(0.00)[yahoo.com]; ASN(0.00)[asn:36646, ipnet:66.163.184.0/21, country:US]; RBL_DBL_DONT_QUERY_IPS(0.00)[66.163.186.205:from]; DWL_DNSWL_NONE(0.00)[yahoo.com:dkim]; MID_RHS_MATCH_FROM(0.00)[]; ARC_NA(0.00)[]; R_DKIM_ALLOW(-0.20)[yahoo.com:s=s2048]; NEURAL_HAM_MEDIUM(-1.00)[-1.000]; FROM_HAS_DN(0.00)[]; NEURAL_SPAM_SHORT(1.00)[1.000]; NEURAL_HAM_LONG(-1.00)[-1.000]; MIME_GOOD(-0.10)[text/plain]; SPAMHAUS_ZRD(0.00)[66.163.186.205:from:127.0.2.255]; TO_MATCH_ENVRCPT_SOME(0.00)[]; RCVD_IN_DNSWL_NONE(0.00)[66.163.186.205:from]; RWL_MAILSPIKE_POSSIBLE(0.00)[66.163.186.205:from]; RCVD_COUNT_TWO(0.00)[2]; MAILMAN_DEST(0.00)[freebsd-stable] X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.34 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 05 Mar 2021 21:11:16 -0000 On 2021-Mar-4, at 14:16, Mark Millard wrote: > Christos Chatzaras chris at cretaforce.gr wrote on > Thu Mar 4 21:41:01 UTC 2021 : >=20 >=20 >> After finding slow filesystem operations with 13.0-BETA2 I did more = tests. >>=20 >> All tests done with same hardware (Seagate ST4000NM0245 4TB HDD - 2 = disks with RAID-1 using gmirror). >>=20 >> Filesystem mounted with noatime. >>=20 >> Command used: >>=20 >> /usr/bin/time -l portsnap extract >>=20 >> but similar differences I see with "/usr/bin/time -l rm -fr = /usr/ports" >=20 > I doubt that "rm -fr" gets large differences of the > type: >=20 > (from 12.2p4:) > 0 messages sent > 0 messages received > vs. (13.0-BETA4 and 14.0-CURRENT:) > 4412 messages sent > 2536379 messages received The more I think above the above figures, the more it seems like 12.2 probably just does not track messsages sent and received, especially given the lack of huge "voluntary context switches" differences vs. 13.0-BETA4 and 14.0-CURRENT. (I expect the message sends/receives to context switch, but I might be wrong.) > In other words, large variations in Inter-Process-Communiciation > counts, especially "received". >=20 > It is not obvious that the "portsnap extract" issue > is dominated by file system I/O vs IPC issues. >=20 > portsanp is a script and does something that looks > like the following, with the "while read" happening > over 29000 times: >=20 > . . . | while read FILE HASH; do > echo ${PORTSDIR}/${FILE} > if ! [ -s "${WORKDIR}/files/${HASH}.gz" ]; then > echo "files/${HASH}.gz not found -- snapshot = corrupt." > return 1 > fi > case ${FILE} in > */) > rm -rf ${PORTSDIR}/${FILE%/} > mkdir -p ${PORTSDIR}/${FILE} > tar -xz --numeric-owner -f = ${WORKDIR}/files/${HASH}.gz \ > -C ${PORTSDIR}/${FILE} > ;; > *) > rm -f ${PORTSDIR}/${FILE} > tar -xz --numeric-owner -f = ${WORKDIR}/files/${HASH}.gz \ > -C ${PORTSDIR} ${FILE} > ;; > esac > done; then >=20 > I expect that the "tar -xz . . . *.gz" sort of commands > also involve internal IPC use. (It looked like the > portsnap script has not changed noticeably since > something like late 2016.) I wonder if the large user and/or sys differences between 12.2 and 13.0-BETA4 might be in process creation given the over 29000 repititions of the loop and the number of processes created per loop iteration. The block input and output figures make no clear difference that I can tell: 29 block input operations 2783 block output operations vs. 716 block input operations 868 block output operations There is also: 11821398 page reclaims vs. 12288156 page reclaims but none of that suggests that scale of differences in: 98.18 real 35.31 user 59.31 sys vs. 163.81 real 71.93 user 107.32 sys So it might be that "time -l" just does not report on what makes up much of the difference. Given the scale of the differences, I'd not expect the variations in the likes of "involuntary context switches" or the like to explain much of the observed differences. (I avoid 14.0-CURRENT for this because of its debug build status that was reported. I avoid 13.0-BETA2 because of know block input/output operation count issues.) > (13.0-BETA2 showed a large "voluntary context switches" > difference as well, but I ignore that middle step in > the version sequence here.) >=20 > So I expect publishing the "rm -fr /usr/ports" figures > from "time -l" would be appropriate. I do not know if > the reports should be via separate topic or not but I > doubt the figures with large differences will be the > same for most-modern vs. older: I do not expect notable > IPC from "rm -fr". >=20 >> ---------- >>=20 >> FreeBSD 12.2p4=20 >>=20 >> 98.18 real 35.31 user 59.31 sys >> 49064 maximum resident set size >> 21 average shared memory size >> 3 average unshared data size >> 86 average unshared stack size >> 11821398 page reclaims >> 0 page faults >> 0 swaps >> 29 block input operations >> 2783 block output operations >> 0 messages sent >> 0 messages received >> 0 signals received >> 354648 voluntary context switches >> 322 involuntary context switches >>=20 >> ---------- >>=20 >> FreeBSD 13.0-BETA2 (2021-02-12) >>=20 >> 497.88 real 76.06 user 120.03 sys >> 49032 maximum resident set size >> 22 average shared memory size >> 3 average unshared data size >> 91 average unshared stack size >> 12288156 page reclaims >> 23 page faults >> 0 swaps >> 29890 block input operations >> 621229 block output operations >> 4412 messages sent >> 2536379 messages received >> 0 signals received >> 1004790 voluntary context switches >> 251 involuntary context switches >>=20 >> -------------- >>=20 >> FreeBSD 13.0-BETA4 (2021-02-26) >>=20 >> 163.81 real 71.93 user 107.32 sys >> 49032 maximum resident set size >> 21 average shared memory size >> 3 average unshared data size >> 89 average unshared stack size >> 12288156 page reclaims >> 5 page faults >> 0 swaps >> 716 block input operations >> 868 block output operations >> 4412 messages sent >> 2536379 messages received >> 0 signals received >> 355244 voluntary context switches >> 277 involuntary context switches >>=20 >> ---------- >>=20 >> FreeBSD 14-CURRENT (2021-03-04) >>=20 >> 255.43 real 74.94 user 148.90 sys >> 49032 maximum resident set size >> 23 average shared memory size >> 3 average unshared data size >> 96 average unshared stack size >> 12288156 page reclaims >> 23 page faults >> 0 swaps >> 31207 block input operations >> 175 block output operations >> 4412 messages sent >> 2536379 messages received >> 0 signals received >> 385527 voluntary context switches >> 369 involuntary context switches >>=20 >> ---------- >>=20 >> Differences between 13.0 and 14-CURRENT maybe related to debugging = features. >>=20 >> But 13.0-BETA4 is slower than 12.2. Does someone have more = information about this? >=20 > Again, I expect that the "time -l" figures may point in > different directions for "portsnap extract" vs. > "rm -fr /usr/ports" in your context. The question may > need to be split because the answers may be different. >=20 While I still think explicit "rm -fr" figures would be good to show, I no longer read so much into the messages sent and received figure differences. =3D=3D=3D Mark Millard marklmi at yahoo.com ( dsl-only.net went away in early 2018-Mar)