From owner-freebsd-stable@freebsd.org Sun Mar 14 22:09:42 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 E2BDE5B4994 for ; Sun, 14 Mar 2021 22:09:42 +0000 (UTC) (envelope-from marklmi@yahoo.com) Received: from sonic308-55.consmr.mail.gq1.yahoo.com (sonic308-55.consmr.mail.gq1.yahoo.com [98.137.68.31]) (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 4DzDHV31bGz4qBn for ; Sun, 14 Mar 2021 22:09:42 +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=1615759780; bh=uxHOJ6Xj9ilBg5OyCWOnuVBYhXCjHAejBito4UfMGyS=; h=X-Sonic-MF:Subject:From:Date:To:From:Subject; b=ibQjLKEMYhfdN3xGk7zhrE5FdEdQpWPq+eeieB9oYeg1fqYJgzdHvby73ZJ8mnMClKQA4lZvz+oJ/ZnfrzTLT6mRA8O06UJb1Dmpc5VbNEW0Uw347GrezUbPw5kfgmBnpge93aYE8iz16woWLoQz84sxdegRv5Ams9Go/leS02NpVgOSV0OY68+NXzmV7Jo1967RyETA5HDW+UwwConklY0eIO8tIr6jgatnlQXBNMlPL4shzC2fJ4wjNutbvi1kePTzPlEtnqb2wNIhHgsm2lxtbdtEn6TTtR1QfXWsXb56QbKTWQsvWZn+3Dx4bRNksnsQhciJ2o71j7o/ztkkZQ== X-YMail-OSG: LRXkRH4VM1lkTY9ThI6ZgNGW8CTsVrulc.8V8nVqVP8bMHLpmpp1NNn10PQCyn0 60LnvRhk3vXFdaVkt9cP.hafsEYjXsDPogeiDGBrjTrBNlA5WWPj6drrYTvXqmAXSqx2qkVlmsov bL082ScFw.5FBoAUU1sQutz4wsSEMeEBb.8JSwYGqB5DZ3rpaPnyGlHUZ_q.Z.RDbrPA2_u3_ZiX oUzT4F67UOKdDQ6FWPGjGxyTcSFKJVBCF8WZLzWJRXJ4GDM1p0J4mCRaJRzCnItsRsHZkvHJ20Nh oUHffg1HPzNrS1WnHQwSBhiANCkzTvy8b4EvZD9.Q2tiK8dDgGHKuvQnMJjlspBo2Y8FKR2vmdbw _FGsVL4rpomGaoAyOvVCM6uH.Pyjl9BP1uyB0onXbSQJs8xMOX7STh8f6Qlczf9VcvQIFTu7wYvB j5hQSdp9Hg9AW0RnRJXx5AAmuvCeS9WyyFMLdZglPVNMgf_PTASXJ51stC7bN2PJBJ2bWMvpDjz_ 3j3opmTtt5HT_0QH9zjLxPFBf1q54WnwCHJ5.JqCSzmR3ov6C2wbe2UI5fKGbBaI.eYCBzYDuEPi OmzNpDQbFnxdlpqPjvZ_d9pXe6_aEA2Xhry2Z_gL2p6FcLc5IwHT86UbDBuLH3OTz68PcNwHvsRH ESoeBGb1vW76NIY1hxWj6J8NJnOoT1xbc41sRn1X8t7o23AZ5fR6i_LulkvCvrmu2E9htHn.gQM7 TibPqNj_Hj0zFbcI8idKeQU7S7_Azeu9uOrwFRPc3swWIzitdDiXybLHVDP2Pz8M51taMmXvX.Ey k0hDdRdB6NUQyXOLV7cm.Et3tF5DlU4OWglLh7viY5x2BWBT2g.xBPBpnRPpzf0dzitqKSN_0FyQ ljrZ.hAAlA5Em0MVKL86B2FZ9HPKAZGK2sWrSsu.TWOjRp_oAfmNKPh1LV32NQyVnBxEB260crzz yJqD8hzKfv35wVcBBaJn7JEHmxOe1lDxtntL9WANRjPIoUS4FDJOz9_gjHVxt1yqpoPCHBsr5IWw G9GAOWBAcLECZ8aCJyKz9DX_UrxfnkL4vwbeJ0G6t8ZAqj4o0VFhOxpdbArurj8a.2icwNe7Kqpo YEpzeo45lqdsFe95gVHliHnXpDgN_VQa32MAGa0rCugFVP1rjt16mmIPoSbipfJZeYq1viZEHHQf eKGN9iEU4Qklte2TwSB8XS4pp5SSC_b30He8hO0QShRljnKOr7aspsZi4IYPsMreb5UX9pC5MR6w tOqm0P0j._YozRr05F6IyJwNMFOZgn2t.83zLWbxzf8WdFuBQMfZUmUtLQxWozEo9PR_u4EtDZjo azKIRuOb0z5UPby8f1t0mOWsUqBfqCEn6mZNuBd3_LZdy9qWoiR6nXZ6FOcRh.aPhH1HEiTfP4OV 06mZpg6nSQxwG0oDyytHweMEpcIlOpEXhCh018G.15LmVPY9trYklMAoWCNJGP3HWM67WWOQEsAu DnCEwrF63apZzBdRbZB7E6UWSPDXQiRZtnEXPsRgroePUdrwlgwZ0hNMaExheBXU5xOAZwdl9OvB naNEj696u5fC5u9uRKU5iqJ_ELeKfvfklfB5TLoqEYYXekoqTWlbjM6wt.8IlSiVnUfJ49b7eXTT IUgTW6J3K8o_AvsyuLGxrBDLi86lpNv_ymfiCgRTh3im0BDiub0x3.1EH8HrccSiuXq9AKN7GMIb sQ_0..NwjZlZxyHn5JHmxkeyQuSb6jYHS8QvG4a_kM9MxUWodqqqHPSqBVs1ZUaRKBGEhcQMkuwX ZJoCB8.2VizhMxLtMcTMBcbK1ExBDcdsdHShOpIxR.jH0UBju2LvGuD4wCcGQivypSHlQ.6IknyE C.Edqxo73ZR8cla4mjw4HmA_wtPYYb7uLzXBfZcZyRVRs6H67NP2JapFOThV9UOuPbH3Mr_DO9c_ s6s51qz065YyRoKlEPxtNBLDjaE7g1tPhy1GBmL1eRBM2TBibrHMDCXYKpQpbOEoFgsU8McMNg0S JTZPz2zz45ZPvDAEN_1CRc7pePHsc4sTK_SaYO3arH4DlIz1ILrsR9UlSwPrg70CQNCJZ9y6zZpO wHHDaAvs8ijbqeyVMpTDwvuUVEFpwIFfI20FyFMWKZJkv36xC3q8bhw.BOPXrOi3KtV8KKGTGZIy PgR24f6ZMT8b_bH1ahmciXZc.sm7vtPaWT.mUkwcBQCJPho8Fk7ulAz76qdWe7MrF7WtGT36uTK4 1Ji.5JfPIatFgBQ781VY0gem4Q0NwyyzphEaPXUYF4ucv7ONiGjsOmJ0PBEMDRsyPNxiTrrU5_wW nkAdCwFVfjOzMr.abVS_Uhe3zEDMYrSiH2mWSi5bDXjde2k0y89Dof1oBa2f6X0yE_zpsrMWlHMl QLWhzf0ZwyrZsNEbhsk5eur8EQJbQ_2Ogq4Df7xIWTyFeHsWSeZRzzdwvROtHNw.E55BFCrmEnCU BMqGzfYUJmhHZ4Qq_GtEY59oyWYA9wN0gLQp_IHV7byr9SAwikTNXixw0OiN3ym7MJqHtHb5ajcq P5FOhAqOi6T1p0n0mQc2Uliw3C9mP4dAATentAGIGySj2RSEGH3jLhonA4vOoU2rPLk6a7yjlEmz ioVF0R_R9PlG7a2QTGcrk6nP4rl.a.HVmnLfT_6XVLsDIp28HWMUJ6_9AY.BS3RympJDUA9bhXk8 18fYaUwFp3FZVKvixy1XKMvCxGn_4a7wPQkE_UY1tZW6pgMbt9XutLcrmyn2reIBK9BwQ4f1w X-Sonic-MF: Received: from sonic.gate.mail.ne1.yahoo.com by sonic308.consmr.mail.gq1.yahoo.com with HTTP; Sun, 14 Mar 2021 22:09:40 +0000 Received: by smtp425.mail.bf1.yahoo.com (VZM Hermes SMTP Server) with ESMTPA ID b0486c35d9eb324d9c76bc9806a1a491; Sun, 14 Mar 2021 22:09:37 +0000 (UTC) Content-Type: text/plain; charset=us-ascii 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 From: Mark Millard In-Reply-To: Date: Sun, 14 Mar 2021 15:09:34 -0700 Cc: Warner Losh , Konstantin Belousov , FreeBSD-STABLE Mailing List Content-Transfer-Encoding: quoted-printable Message-Id: References: <12705C29-53EA-4484-8291-C409AF4B3DE5.ref@yahoo.com> <12705C29-53EA-4484-8291-C409AF4B3DE5@yahoo.com> To: Kevin Oberman X-Mailer: Apple Mail (2.3654.60.0.2.21) X-Rspamd-Queue-Id: 4DzDHV31bGz4qBn X-Spamd-Bar: ---- X-Spamd-Result: default: False [-4.00 / 15.00]; REPLY(-4.00)[] 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: Sun, 14 Mar 2021 22:09:42 -0000 On 2021-Mar-14, at 11:09, Kevin Oberman wrote: > . . . > =20 > Seems to only occur on large r/w operations from/to the same disk. "sp > big-file /other/file/on/same/disk" or tar/untar operations on large = files. > Hit this today updating firefox. >=20 > I/O starts at >40MB/s. Dropped to about 1.5MB/s. If I tried doing = other > things while it was running slowly, the disk would appear to lock up. = E.g. > pwd(1) seemed to completely lock up the system, but I could still ping = it > and, after about 30 seconds, things came back to life. It was also not > instantaneous. Disc activity dropped to <1MB/s for a few seconds = before > everything froze. >=20 > During the untar of firefox, I saw; this several times. I also looked = at my > console where I found these errors during : > swap_pager: indefinite wait buffer: bufobj: 0, blkno: 55043, size: = 8192 > swap_pager: indefinite wait buffer: bufobj: 0, blkno: 51572, size: = 4096 Does anyone know: Are those messages normal "reading is taking a rather long time" notices or is their presence more useful information in some way about the type of problem or context for the problem? As for the tests: Are these messages always present when near a time frame when the problem occurs? Never present in a near time frame to a period when the problem does not occur? It appears that the messages are associated with reading the disk(s), not directly with writing them, where the reads take more than "hz * 20" time units to complete. (I'm looking at main (14) code.) What might contribute to the time taken for the pending read(s)? /* * swap_pager_getpages() - bring pages in from swap * * Attempt to page in the pages in array "ma" of length "count". = The * caller may optionally specify that additional pages preceding = and * succeeding the specified range be paged in. The number of such = pages * is returned in the "rbehind" and "rahead" parameters, and they = will * be in the inactive queue upon return. * * The pages in "ma" must be busied and will remain busied upon = return. */ static int swap_pager_getpages_locked(vm_object_t object, vm_page_t *ma, int count, int *rbehind, int *rahead) { . . . /* * Wait for the pages we want to complete. VPO_SWAPINPROG is = always * cleared on completion. If an I/O error occurs, SWAPBLK_NONE * is set in the metadata for each page in the request. */ VM_OBJECT_WLOCK(object); /* This could be implemented more efficiently with aflags */ while ((ma[0]->oflags & VPO_SWAPINPROG) !=3D 0) { ma[0]->oflags |=3D VPO_SWAPSLEEP; VM_CNT_INC(v_intrans); if (VM_OBJECT_SLEEP(object, &object->handle, PSWP, "swread", hz * 20)) { printf( "swap_pager: indefinite wait buffer: bufobj: %p, blkno: %jd, size: = %ld\n", bp->b_bufobj, (intmax_t)bp->b_blkno, = bp->b_bcount); } } VM_OBJECT_WUNLOCK(object); . . . where: #define VM_OBJECT_SLEEP(object, wchan, pri, wmesg, timo) = \ rw_sleep((wchan), &(object)->lock, (pri), (wmesg), (timo)) and: #define rw_sleep(chan, rw, pri, wmesg, timo) = \ _sleep((chan), &(rw)->lock_object, (pri), (wmesg), = \ tick_sbt * (timo), 0, C_HARDCLOCK) (I do not claim to be able to interpret the implications of the code that leads to the messages. But seeing some of the code might prompt a thought by someone that knows the code's context and operation.) > . . . > Backing off to Mar. 4 was not an improvement. My untar did seem better = for a couple of minutes, but then the display froze again for 30 seconds = and disk performance dropped to <1M. You were able to see the disk performance drop while the display was frozen? It might not be the best for monitoring but I'll ask this in terms of top output: Does Inact, Laundry, Wired, Free, or other such show anything fairly unique for around the problematical time frame(s)? > then things got really bad and behaved in a manner that was baffling = to me. The screen froze again, but stayed frozen after half a minute. I = clicked on a couple of buttons in Firefox to no effect and then hit = ctrl-q to quit. After the long pause, I pressed the power button to try = to force a shutdown. Suddenly, it started unwinding everything I had = done during the freeze. My browser did the updates from my mouse clicks = including quitting. It then switched to a different workspace from = ctrl-alt-right and did a clean shutdown. ????=20 >=20 > Do I also have a graphics issue? Examining log files show no = indication that anything was happening. SMART shows no errors and = reasonable values for everything. No indication of a HW problem. The = system performs well unless I do something that tries a bulk disk data = move. Building world takes about 75 minutes. I just have a very hard = time building big ports. Almost like things were stuck-sleeping and then the sleep(s) finished? =3D=3D=3D Mark Millard marklmi at yahoo.com ( dsl-only.net went away in early 2018-Mar)