From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from kanga.kvack.org (kanga.kvack.org [205.233.56.17]) by smtp.lore.kernel.org (Postfix) with ESMTP id A108DC4167B for ; Mon, 27 Nov 2023 04:34:40 +0000 (UTC) Received: by kanga.kvack.org (Postfix) id C89E36B0319; Sun, 26 Nov 2023 23:34:39 -0500 (EST) Received: by kanga.kvack.org (Postfix, from userid 40) id C39F46B031A; Sun, 26 Nov 2023 23:34:39 -0500 (EST) X-Delivered-To: int-list-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix, from userid 63042) id B02136B031B; Sun, 26 Nov 2023 23:34:39 -0500 (EST) X-Delivered-To: linux-mm@kvack.org Received: from relay.hostedemail.com (smtprelay0016.hostedemail.com [216.40.44.16]) by kanga.kvack.org (Postfix) with ESMTP id A1B986B0319 for ; Sun, 26 Nov 2023 23:34:39 -0500 (EST) Received: from smtpin19.hostedemail.com (a10.router.float.18 [10.200.18.1]) by unirelay01.hostedemail.com (Postfix) with ESMTP id 799D51CA870 for ; Mon, 27 Nov 2023 04:34:39 +0000 (UTC) X-FDA: 81502468278.19.0EDD8FF Received: from mail-lf1-f42.google.com (mail-lf1-f42.google.com [209.85.167.42]) by imf03.hostedemail.com (Postfix) with ESMTP id 93ACD2000C for ; Mon, 27 Nov 2023 04:34:37 +0000 (UTC) Authentication-Results: imf03.hostedemail.com; dkim=pass header.d=google.com header.s=20230601 header.b=LfXGddIM; spf=pass (imf03.hostedemail.com: domain of dvyukov@google.com designates 209.85.167.42 as permitted sender) smtp.mailfrom=dvyukov@google.com; dmarc=pass (policy=reject) header.from=google.com ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=hostedemail.com; s=arc-20220608; t=1701059677; h=from:from:sender:reply-to:subject:subject:date:date: message-id:message-id:to:to:cc:cc:mime-version:mime-version: content-type:content-type:content-transfer-encoding: in-reply-to:in-reply-to:references:references:dkim-signature; bh=IXbKy2pJw1weWM2AUX6qsAkpX0IgEY8LocF0NM/epjw=; b=YWj17A2nXe5Wpcpyy92UVtfLiC7wko+2uXk7K0fBRcdch2zWoG28KO67+tduDU8Erat3i8 xWyxWtICuMfnW84xZkchTlt/Up+bJekDGKrZ8t5UoRLlaf0luPoyFZEKhyTEPCTnBtxSaE lsHEg0+e+HKntYMwlOUlpFBUK3igJYs= ARC-Seal: i=1; s=arc-20220608; d=hostedemail.com; t=1701059677; a=rsa-sha256; cv=none; b=2WU77yBFXeuWKpS4SZCK8dW2yR12w27Gpctyj6Z1o1+pIXDtEhSy5K0Fee3n09pUwtxapw 9uxeNNYgVAJkX/HldaEWPlhXlhNgHSEk+I81E9hIzqv+jizrfJbMJiKLypp0jGdZOwsHpl tmMnS0PLC4rf6URsZqYScJCvEyj8Ll4= ARC-Authentication-Results: i=1; imf03.hostedemail.com; dkim=pass header.d=google.com header.s=20230601 header.b=LfXGddIM; spf=pass (imf03.hostedemail.com: domain of dvyukov@google.com designates 209.85.167.42 as permitted sender) smtp.mailfrom=dvyukov@google.com; dmarc=pass (policy=reject) header.from=google.com Received: by mail-lf1-f42.google.com with SMTP id 2adb3069b0e04-50ba8177c9fso3616e87.1 for ; Sun, 26 Nov 2023 20:34:37 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=20230601; t=1701059676; x=1701664476; darn=kvack.org; h=cc:to:subject:message-id:date:from:in-reply-to:references :mime-version:from:to:cc:subject:date:message-id:reply-to; bh=IXbKy2pJw1weWM2AUX6qsAkpX0IgEY8LocF0NM/epjw=; b=LfXGddIM0kbe5oCvhIHWx+798bgFXg7BGkOuuOAHICRTzt9re4teqCpW49EKM3buu4 ywdvhBtq0UOWZlI8cITMzKAZGui6u+tRoN4oS4tcfo2XLeiGUJ3JTxeGvbIm+TZlLrwS dfrTvpBQzm7F76Z6vg/iznCmonqzlIPMLZuECB9S5d0hiFlHA/SdM+BG4Iyx/3geYK11 7zecwCXoa06LKLdmJTSsNHbdP1bMeqnQUqeFIsl7A6ZPglNHU7WnDHHzp64MHH4+3e++ H6cbV3k4hQ+W1rf3K8KQzV/xsaUp3I9I5kM1tGydP5yBw9ZbWaJ3HHCpkTyNvZPWFT+5 bEKw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1701059676; x=1701664476; h=cc:to:subject:message-id:date:from:in-reply-to:references :mime-version:x-gm-message-state:from:to:cc:subject:date:message-id :reply-to; bh=IXbKy2pJw1weWM2AUX6qsAkpX0IgEY8LocF0NM/epjw=; b=skORmxfLexK1xfoAIiUae2NRCi25iFbhLTjiM4GoQ2XqeESNJxxP3V8HjLJOctPqI5 QO1bJqgBLC4/MQJdmUHra3+s5Aqa3/KvSn3SL6QGM9AYjKLykN+6SXPyhnEEWDjq1eTI nYgH+It//UVYWeqSi8eaDf23MDOfcdPozDhm4XZfn8MNFQxcDm+1JjdemWsiqSy/5dx5 JT7Fsfp1P5Ysm9CcSjeIWkKbru/Lm2B8ZLjb/ZR7gVpQfdOqELzBXSgZAysnyN/ClXDL RDioJwZj3vwonP7yKYCXsh9JZyg17ufyLk+s+EcOQMYjTfbhKb0OpCLIugiepZSzd5FI Wxhw== X-Gm-Message-State: AOJu0YwHvGfhPHLARBj5u1FCGw76f5Kyv3TA56ArvQbfE7lnkgpz2f8r KdUyL7oT1gR2nZjkxQuZlO3iWQ27kL9V2n6rgJUSxg== X-Google-Smtp-Source: AGHT+IFhdT60DfmJFK01YP5LJxJl2q5WHKddBuvyqA3O+DhvY0L2910Po9fgOI0KxYcxbbBEVJoe6jXahBGdrtcbosA= X-Received: by 2002:a05:6512:239e:b0:501:a2b9:6046 with SMTP id c30-20020a056512239e00b00501a2b96046mr452354lfv.7.1701059675534; Sun, 26 Nov 2023 20:34:35 -0800 (PST) MIME-Version: 1.0 References: In-Reply-To: From: Dmitry Vyukov Date: Mon, 27 Nov 2023 05:34:22 +0100 Message-ID: Subject: Re: [PATCH v2] kasan: Record and report more information To: Juntong Deng Cc: ryabinin.a.a@gmail.com, glider@google.com, andreyknvl@gmail.com, vincenzo.frascino@arm.com, akpm@linux-foundation.org, kasan-dev@googlegroups.com, linux-mm@kvack.org, linux-kernel@vger.kernel.org, linux-kernel-mentees@lists.linuxfoundation.org Content-Type: text/plain; charset="UTF-8" X-Rspamd-Queue-Id: 93ACD2000C X-Rspam-User: X-Rspamd-Server: rspam11 X-Stat-Signature: h8ns4gkmndi8mpnmqpjm48c3eqyynwgo X-HE-Tag: 1701059677-15122 X-HE-Meta: U2FsdGVkX19m7SuKCGcFJf0HXA/XGETsim5BAnWMz1UXCrybWod3/J5lU9Gbg/NoMMAiw4oCcHxs/4T8dUIaXkZWOB/yVTx4+y6mjiFQyQZHGrr6dHcOcRwQG4fuWiGAQoHN+2m72jCjo3zZohhz4xWjxFSGZlq9H/PEc9rWMBgw9V+9btDOVQTdNMCkQwRKzdMWpmkbXAQvXBX8MDre4I9WJRaEeQViYC9fIII19YaCZUtwrAFJPRo5nFBZ8WXs/JxhY8Z21XyOAUZBn6iR+wDjOXvLzRgOkZZ/7scq+mio367v1VsdaiLmBkr4su49u6lgK70rFl2pFwy/nc8rx0VGVA19tEDYlWqlvXpYKNh9CsWp0bJS75YN2XHF0TL7+IW36p6EGnFDov6W1dgJ+uCTzSDUIm6z2iKoQ5BwMfxBC2CznmHCJvEAWMneytc6AOTtNTA1VAAVx7unY3YRtw4/GpG8Ao1ox5vrpJBAqA8618+SuwEbx804thX3FmOM/O7MnFQvSTYRb4RPSUJdMGXaRaLK0pkwWKsS75v5DSfPMdZA2HQSgVP+vCIiw0cmMbTc6u8cshxzp5NjLwAA/1QyrOJ+zu+5CjBPRN7NQpJ3n4D8eKbyTTKbkPP8goy1dc59apI/KJj+TnMTvccwMfjRJxuv9stzseAp6XgwrT8n7R4IYlsIUWFFRXlqAj7OGWWhMd4qBeMWmXSM5ymGbpOuiikeRVYHXqG1K1XQSVT7HPF6DBm26/NrtO8ASg0is/7PKhLHvKh5TwRcGQByr7C+EmvS4F/vJu2Rt3jrmjnWw1e2FQvvz/an7qDupljVS8x3PIRr2EzxZRKPNZgVpqT1RIG1CIIJ/UqlhQHh76EMOMhAufEe+KIUq8zvYEsvdvpM4LabdcOqLV0Uk0KFqBEWWmUAXd/XknirExFgXlrhoGdOrUasqcBYj+RJPHr0W+HfenwG4X7yd5H1Lni 43+aPnlW HeqGFuUy2w7UbjJKQSM9pE5PyBOh6YA2CFtD6Yc2Q6aR74DKsQRGSC6/eo0vx7Xg/X1KIcKNi0vkwgPfk7NZ2Z4ITh1DLMuqpxbS3flSeBQZQpZTCBhImXpI1Bvo1G6DHXHXeuuPT7mzIZLlNePSAAFjTnt53pJY+ImuvMqMd7Xdh8puAbBfDre2VuEHNVZolkrOIdQiJ7oK8A2YCmdg9BZbIeCen/VMazPo2NJeJv1dN+duYGt//ep1VMey/XfEGsVTcmgwzUIpGJfuOkWu/nrlSemB1ObZ6bB42GzzV/TMnjO6XxmVkOge9isldCD4DDADLthbKZoiCxR3umqqJneit5PNFlEDis4vn X-Bogosity: Ham, tests=bogofilter, spamicity=0.000000, version=1.2.4 Sender: owner-linux-mm@kvack.org Precedence: bulk X-Loop: owner-majordomo@kvack.org List-ID: List-Subscribe: List-Unsubscribe: On Sun, 26 Nov 2023 at 23:25, Juntong Deng wrote: > > Record and report more information to help us find the cause of the > bug and to help us correlate the error with other system events. > > This patch adds recording and showing CPU number and timestamp at > allocation and free (controlled by CONFIG_KASAN_EXTRA_INFO). The > timestamps in the report use the same format and source as printk. > > Error occurrence timestamp is already implicit in the printk log, > and CPU number is already shown by dump_stack_lvl, so there is no > need to add it. > > In order to record CPU number and timestamp at allocation and free, > corresponding members need to be added to the relevant data structures, > which will lead to increased memory consumption. > > In Generic KASAN, members are added to struct kasan_track. Since in > most cases, alloc meta is stored in the redzone and free meta is > stored in the object or the redzone, memory consumption will not > increase much. > > In SW_TAGS KASAN and HW_TAGS KASAN, members are added to > struct kasan_stack_ring_entry. Memory consumption increases as the > size of struct kasan_stack_ring_entry increases (this part of the > memory is allocated by memblock), but since this is configurable, > it is up to the user to choose. > > Signed-off-by: Juntong Deng > --- > V1 -> V2: Use bit field to reduce memory consumption. Add more detailed > config help. Cancel printing of redundant error occurrence timestamp. > > lib/Kconfig.kasan | 21 +++++++++++++++++++++ > mm/kasan/common.c | 10 ++++++++++ > mm/kasan/kasan.h | 10 ++++++++++ > mm/kasan/report.c | 6 ++++++ > mm/kasan/report_tags.c | 16 ++++++++++++++++ > mm/kasan/tags.c | 17 +++++++++++++++++ > 6 files changed, 80 insertions(+) > > diff --git a/lib/Kconfig.kasan b/lib/Kconfig.kasan > index 935eda08b1e1..8653f5c38be7 100644 > --- a/lib/Kconfig.kasan > +++ b/lib/Kconfig.kasan > @@ -207,4 +207,25 @@ config KASAN_MODULE_TEST > A part of the KASAN test suite that is not integrated with KUnit. > Incompatible with Hardware Tag-Based KASAN. > > +config KASAN_EXTRA_INFO > + bool "Record and report more information" > + depends on KASAN > + help > + Record and report more information to help us find the cause of the > + bug and to help us correlate the error with other system events. > + > + Currently, the CPU number and timestamp are additionally > + recorded for each heap block at allocation and free time, and > + 8 bytes will be added to each metadata structure that records > + allocation or free information. > + > + In Generic KASAN, each kmalloc-8 and kmalloc-16 object will add > + 16 bytes of additional memory consumption, and each kmalloc-32 > + object will add 8 bytes of additional memory consumption, not > + affecting other larger objects. > + > + In SW_TAGS KASAN and HW_TAGS KASAN, depending on the stack_ring_size > + boot parameter, it will add 8 * stack_ring_size bytes of additional > + memory consumption. > + > endif # KASAN > diff --git a/mm/kasan/common.c b/mm/kasan/common.c > index b5d8bd26fced..2f0884c762b7 100644 > --- a/mm/kasan/common.c > +++ b/mm/kasan/common.c > @@ -20,6 +20,7 @@ > #include > #include > #include > +#include > #include > #include > #include > @@ -49,6 +50,15 @@ depot_stack_handle_t kasan_save_stack(gfp_t flags, depot_flags_t depot_flags) > > void kasan_set_track(struct kasan_track *track, gfp_t flags) > { > +#ifdef CONFIG_KASAN_EXTRA_INFO > + u32 cpu = raw_smp_processor_id(); > + u64 ts_nsec = local_clock(); > + unsigned long rem_usec = do_div(ts_nsec, NSEC_PER_SEC) / 1000; > + > + track->cpu = cpu; > + track->ts_sec = ts_nsec; > + track->ts_usec = rem_usec; > +#endif /* CONFIG_KASAN_EXTRA_INFO */ > track->pid = current->pid; > track->stack = kasan_save_stack(flags, > STACK_DEPOT_FLAG_CAN_ALLOC | STACK_DEPOT_FLAG_GET); > diff --git a/mm/kasan/kasan.h b/mm/kasan/kasan.h > index b29d46b83d1f..2a37baa4ce2f 100644 > --- a/mm/kasan/kasan.h > +++ b/mm/kasan/kasan.h > @@ -187,6 +187,11 @@ static inline bool kasan_requires_meta(void) > struct kasan_track { > u32 pid; > depot_stack_handle_t stack; > +#ifdef CONFIG_KASAN_EXTRA_INFO > + u64 cpu:20; > + u64 ts_sec:22; > + u64 ts_usec:22; > +#endif /* CONFIG_KASAN_EXTRA_INFO */ > }; > > enum kasan_report_type { > @@ -278,6 +283,11 @@ struct kasan_stack_ring_entry { > u32 pid; > depot_stack_handle_t stack; > bool is_free; > +#ifdef CONFIG_KASAN_EXTRA_INFO > + u64 cpu:20; > + u64 ts_sec:22; > + u64 ts_usec:22; > +#endif /* CONFIG_KASAN_EXTRA_INFO */ > }; > > struct kasan_stack_ring { > diff --git a/mm/kasan/report.c b/mm/kasan/report.c > index e77facb62900..8cd8f6e5cf24 100644 > --- a/mm/kasan/report.c > +++ b/mm/kasan/report.c > @@ -262,7 +262,13 @@ static void print_error_description(struct kasan_report_info *info) > > static void print_track(struct kasan_track *track, const char *prefix) > { > +#ifdef CONFIG_KASAN_EXTRA_INFO > + pr_err("%s by task %u on cpu %d at %u.%06us:\n", > + prefix, track->pid, track->cpu, > + track->ts_sec, track->ts_usec); > +#else > pr_err("%s by task %u:\n", prefix, track->pid); > +#endif /* CONFIG_KASAN_EXTRA_INFO */ > if (track->stack) > stack_depot_print(track->stack); > else > diff --git a/mm/kasan/report_tags.c b/mm/kasan/report_tags.c > index 55154743f915..bf895b1d2dc2 100644 > --- a/mm/kasan/report_tags.c > +++ b/mm/kasan/report_tags.c > @@ -27,6 +27,16 @@ static const char *get_common_bug_type(struct kasan_report_info *info) > return "invalid-access"; > } > > +#ifdef CONFIG_KASAN_EXTRA_INFO > +static void kasan_complete_extra_report_info(struct kasan_track *track, > + struct kasan_stack_ring_entry *entry) > +{ > + track->cpu = entry->cpu; > + track->ts_sec = entry->ts_sec; > + track->ts_usec = entry->ts_usec; > +} > +#endif /* CONFIG_KASAN_EXTRA_INFO */ > + > void kasan_complete_mode_report_info(struct kasan_report_info *info) > { > unsigned long flags; > @@ -73,6 +83,9 @@ void kasan_complete_mode_report_info(struct kasan_report_info *info) > > info->free_track.pid = entry->pid; > info->free_track.stack = entry->stack; > +#ifdef CONFIG_KASAN_EXTRA_INFO > + kasan_complete_extra_report_info(&info->free_track, entry); > +#endif /* CONFIG_KASAN_EXTRA_INFO */ > free_found = true; > > /* > @@ -88,6 +101,9 @@ void kasan_complete_mode_report_info(struct kasan_report_info *info) > > info->alloc_track.pid = entry->pid; > info->alloc_track.stack = entry->stack; > +#ifdef CONFIG_KASAN_EXTRA_INFO > + kasan_complete_extra_report_info(&info->alloc_track, entry); > +#endif /* CONFIG_KASAN_EXTRA_INFO */ > alloc_found = true; > > /* > diff --git a/mm/kasan/tags.c b/mm/kasan/tags.c > index 739ae997463d..c172e115b9bb 100644 > --- a/mm/kasan/tags.c > +++ b/mm/kasan/tags.c > @@ -13,6 +13,7 @@ > #include > #include > #include > +#include > #include > #include > #include > @@ -93,6 +94,19 @@ void __init kasan_init_tags(void) > } > } > > +#ifdef CONFIG_KASAN_EXTRA_INFO > +static void save_extra_info(struct kasan_stack_ring_entry *entry) > +{ > + u32 cpu = raw_smp_processor_id(); > + u64 ts_nsec = local_clock(); > + unsigned long rem_usec = do_div(ts_nsec, NSEC_PER_SEC) / 1000; > + > + entry->cpu = cpu; > + entry->ts_sec = ts_nsec; > + entry->ts_usec = rem_usec; I would timestamp as a single field in all structs and convert it to sec/usec only when we print it. It would make all initialization and copying shorter. E.g. this function can be just: entry->cpu = raw_smp_processor_id(); entry->timestamp = local_clock() / 1024; Dividing by 1024 is much faster and gives roughly the same precision. This can be unscaled during reporting: u64 sec = entry->timestamp * 1024; unsigned long usec = do_div(sec, NSEC_PER_SEC) / 1000; But otherwise the patch looks good to me. Reviewed-by: Dmitry Vyukov > +} > +#endif /* CONFIG_KASAN_EXTRA_INFO */ > + > static void save_stack_info(struct kmem_cache *cache, void *object, > gfp_t gfp_flags, bool is_free) > { > @@ -128,6 +142,9 @@ static void save_stack_info(struct kmem_cache *cache, void *object, > entry->pid = current->pid; > entry->stack = stack; > entry->is_free = is_free; > +#ifdef CONFIG_KASAN_EXTRA_INFO > + save_extra_info(entry); > +#endif /* CONFIG_KASAN_EXTRA_INFO */ > > entry->ptr = object; > > -- > 2.39.2 >