Received-SPF: pass (google.com: domain of linux-kernel+bounces-170585-linux.lists.archive=gmail.com@vger.kernel.org designates 147.75.48.161 as permitted sender) client-ip=147.75.48.161;
From: John Hubbard <jhubbard@nvidia.com>
To: Andy Lutomirski <luto@kernel.org>
Cc: Dave Hansen <dave.hansen@linux.intel.com>,
	Peter Zijlstra <peterz@infradead.org>,
	Thomas Gleixner <tglx@linutronix.de>,
	Ingo Molnar <mingo@redhat.com>,
	Borislav Petkov <bp@alien8.de>,
	x86@kernel.org,
	"H . Peter Anvin" <hpa@zytor.com>,
	LKML <linux-kernel@vger.kernel.org>,
	linux-mm@kvack.org,
	John Hubbard <jhubbard@nvidia.com>
Subject: [PATCH] x86/fault: speed up uffd-unit-test by 10x: rate-limit "MCE: Killing" logs
Date: Mon,  6 May 2024 19:29:39 -0700
Message-ID: <20240507022939.236896-1-jhubbard@nvidia.com>
Content-Transfer-Encoding: 8bit
Content-Type: text/plain
Precedence: bulk
MIME-Version: 1.0
X-MS-Exchange-AntiSpam-MessageData-ChunkCount: 1
X-MS-Exchange-AntiSpam-MessageData-0:
	=?us-ascii?Q?o9ezY0XY/DIKEVAhBcNeVkVM27juuJAz3OnvziRLAnyC4w6BCcS7+Uwgx9pm?=
 =?us-ascii?Q?gE8Ix0Y5INzBtY3JRnrKrAdteKZbtS9qehIZ2mlj2Wi8ZY28Wtv6eTpl6jCO?=
 =?us-ascii?Q?fmnWqRb0gkXCQma3wqu961Aync+NX1chXjpKk0uYdi7z9Be6D8fBL8cXIgbQ?=
 =?us-ascii?Q?maTpphhx0VPe/4GggLnrVJ39uoWWm+y7dIywTeaPnAtT6mmBFi3RBNu1g9xU?=
 =?us-ascii?Q?vxHhIo1/hubxsuUQdQ5NbOt5jeH/NKByA+pg7TOV/Bqz5MyVUdey1VnRwZw4?=
 =?us-ascii?Q?9CAaCjRBMK0YGV9tJQCdHfwO4MY8N0ldl2E56oKniZNA4oh/DbdfWfV9UT++?=
 =?us-ascii?Q?HsNlRPmzwQ8v8dA3WXQ4zGFwNalrjcJTKC5uJnVbaG9TUTJWne5yK3Cc/RaW?=
 =?us-ascii?Q?I0UcSxcrCYu7J+p4mzXPwx47OUcVdROyEPmBzIYzpXBkSEWoSh72D6GSqt2C?=
 =?us-ascii?Q?RQg9HHwH1CVerFMcGaBOuc2823cbm7Xkb7B3JH/+M5vwCu1mRkGe8N8Lrrd9?=
 =?us-ascii?Q?1b4diYiQhI2270ESjC0rvGyWcOWgEpnoUhtR3UkYW0IjV8D9rotfAPKCknVr?=
 =?us-ascii?Q?8iOEtSBaz1N4yaHt0UXkj9hRlFLqrPeVAJDfmQRAY3N95Y/1QAWmTbfkmZoD?=
 =?us-ascii?Q?EcfxUpMb4Mub79B8VxkmwMStOBnykgLxt5pWup4z51FP2fr1mgVTRQ8k+byv?=
 =?us-ascii?Q?4EL2miu/oYf3DDkaMDi7C5hQnuTR6EFlpNS3t14LHZTIDGQsJA3szkuDnm+f?=
 =?us-ascii?Q?FtKE1cMqAd6TtBrGTKdwbaf4f/YXt+Ok3vU0oLTD9C7hLr3XBdwXn2SpdzRw?=
 =?us-ascii?Q?bksosZxTI/EzeyERlKu/qAS7wkOgTwKOIX1wK14b57ixvVdCqqRykgXD+sU2?=
 =?us-ascii?Q?bVyUS7w3BkEXphjbUD07sChBVN9Z4WMeKiCzBFg1QaITVsbKmoimDIsalKIo?=
 =?us-ascii?Q?BcOVyMrfhQi6dPAwePsPVgwYqXcZxR8UUv+YfctCqA9PjyxsSlgeiV/s/ETC?=
 =?us-ascii?Q?a84Jf+ihw0rxsoxX7W5WlyM0gNXTMq9d8kxuRLHdSgVGATvUTQqxSgpfEFS4?=
 =?us-ascii?Q?GVfF6fpTe+xcn2oxfPb3Sr7c4xb0QyZflpBxuInBie+leaaVqhRxtcVcVhkJ?=
 =?us-ascii?Q?D1oTsHksfbOXHO+/5fLXoRTxtGt44BQsOingOBOmLw2jf9sDjlYfhhcEopJa?=
 =?us-ascii?Q?cviqPo8jaIPui0N8K+ZmQD5hOb1W2FnJaOZ1wOBad3Q36Bq7ts3QyLoVanjN?=
 =?us-ascii?Q?KSEFFXjbuupSEWb25Z6QcCLwTdw2V06y84DClJHO16GSEBzcbBhX0bHu9f2H?=
 =?us-ascii?Q?o6UoJoocNh/B82jdwbqfGUUX2KHUkJo9+bW3uH+fmLtW4iOFE/wKT1AN2tme?=
 =?us-ascii?Q?THnk24H8JJzAvVOOg6zrLZo/HNU1Yj6h45vRDXdYhz50FfYZG0R5Pcqaq6Pq?=
 =?us-ascii?Q?TUV4TCKPmajVp0tPjXJf/+BbmEWuP23SwtvnEtQW4nlTN6Zoww144k3hkJJx?=
 =?us-ascii?Q?68vYxWypuA+WQStRCl2Y3lr0fwIPOBzkc6R22TeCMBLUvTZJlD8EoNE90eqv?=
 =?us-ascii?Q?L8RrsgmCrH+P2HXw1QMiYE79iPi5UAuEK3YTNB+8?=
X-OriginatorOrg: Nvidia.com
X-MS-Exchange-CrossTenant-Network-Message-Id: 61b320d6-d61b-4a41-12a0-08dc6e3d8e82
X-MS-Exchange-CrossTenant-AuthSource: DM6PR12MB4140.namprd12.prod.outlook.com
X-MS-Exchange-CrossTenant-AuthAs: Internal
X-MS-Exchange-CrossTenant-OriginalArrivalTime: 07 May 2024 02:29:44.3862
 (UTC)
X-MS-Exchange-CrossTenant-FromEntityHeader: Hosted
X-MS-Exchange-CrossTenant-Id: 43083d15-7273-40c1-b7db-39efd9ccc17a
X-MS-Exchange-CrossTenant-MailboxType: HOSTED
X-MS-Exchange-CrossTenant-UserPrincipalName: oTtwXzF8bFHelC7iE+CYM243Kw7JRNkl6SV4OPpaJ+Mwz3zrXw59u/zbqxyCMXcTMSn9sNb5rua8/bUuJ/Naxg==
X-MS-Exchange-Transport-CrossTenantHeadersStamped: SN7PR12MB7022

If a system experiences a lot of memory failures, then any associated
printk() output really needs to be rate-limited. I noticed this while
running selftests/mm/uffd-unit-tests, which logs 12,305 lines of output,
adding (on my system) an extra 97 seconds of runtime due to printk time.

The test normally only takes about 10 seconds, and the enclosing set of
mm selftests normally takes 305 seconds, so the additional 97 seconds
really hurts.

Generating lots of memory poisoning events seems like a valid use case,
by which I mean that this is not just a testing artifact. And that's why
the fix applies to the code that directly generates the output, rather
than the selftest that triggers it.

With this patch, all but 10 lines are suppressed, thus speeding up that
particular selftest by 90% (runtime drops from 107 seconds, to 10.6
seconds).

Signed-off-by: John Hubbard <jhubbard@nvidia.com>
---
 arch/x86/mm/fault.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/arch/x86/mm/fault.c b/arch/x86/mm/fault.c
index bba4e020dd64..e4f3c7721f45 100644
--- a/arch/x86/mm/fault.c
+++ b/arch/x86/mm/fault.c
@@ -928,7 +928,7 @@ do_sigbus(struct pt_regs *regs, unsigned long error_code, unsigned long address,
 		struct task_struct *tsk = current;
 		unsigned lsb = 0;
 
-		pr_err(
+		pr_err_ratelimited(
 	"MCE: Killing %s:%d due to hardware memory corruption fault at %lx\n",
 			tsk->comm, tsk->pid, address);
 		if (fault & VM_FAULT_HWPOISON_LARGE)

base-commit: dccb07f2914cdab2ac3a5b6c98406f765acab803
prerequisite-patch-id: b901ece2a5b78503e2fb5480f20e304d36a0ea27
-- 
2.45.0