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 9B554C0755A for ; Mon, 27 Nov 2023 09:38:28 +0000 (UTC) Received: by kanga.kvack.org (Postfix) id 2E6436B032C; Mon, 27 Nov 2023 04:38:28 -0500 (EST) Received: by kanga.kvack.org (Postfix, from userid 40) id 2975D6B032D; Mon, 27 Nov 2023 04:38:28 -0500 (EST) X-Delivered-To: int-list-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix, from userid 63042) id 15DFA6B032E; Mon, 27 Nov 2023 04:38:28 -0500 (EST) X-Delivered-To: linux-mm@kvack.org Received: from relay.hostedemail.com (smtprelay0010.hostedemail.com [216.40.44.10]) by kanga.kvack.org (Postfix) with ESMTP id 071BE6B032C for ; Mon, 27 Nov 2023 04:38:28 -0500 (EST) Received: from smtpin11.hostedemail.com (a10.router.float.18 [10.200.18.1]) by unirelay09.hostedemail.com (Postfix) with ESMTP id CD4F48019C for ; Mon, 27 Nov 2023 09:38:27 +0000 (UTC) X-FDA: 81503233854.11.406AB8F Received: from mail-lf1-f49.google.com (mail-lf1-f49.google.com [209.85.167.49]) by imf22.hostedemail.com (Postfix) with ESMTP id 036EEC000E for ; Mon, 27 Nov 2023 09:38:25 +0000 (UTC) Authentication-Results: imf22.hostedemail.com; dkim=pass header.d=google.com header.s=20230601 header.b=CDZI7lWp; spf=pass (imf22.hostedemail.com: domain of dvyukov@google.com designates 209.85.167.49 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=1701077906; 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=yXbJLlN8zN8yxyWwSZeLI9CkhU0ZX6ImmCRBdSzQVgU=; b=Bq/d/ONqbpDIQYMhIeoqlxCCmkfZdlfwelYMDXxNveF88KoDaNtA0145Tv3blAQaGwo7R+ ZCVeMiOGBaCDjUp5DT+MCTVo7YweE5rBh5RYIKGOYN9GoM2Ha2olcFknXRHT9V+HcqKXrm kknCOJy8V74Hx6VGPSkjU2tIs045SMQ= ARC-Seal: i=1; s=arc-20220608; d=hostedemail.com; t=1701077906; a=rsa-sha256; cv=none; b=miM4108hsHiIVbEogAKG7OO3fiJewwxBhOpRHhNinfqQfBdo4W6pRH4Q0REFeBeq+WCY6Y tQfiCXDe9Nn4m0yepPZQGPRGO5U9CovDYas5azEkQuLjkhXMJYV/KmYC4kpJw4YerbWQmv 5EOuRCRs7WwwtgZaJK1v5RiFOQ9GN7E= ARC-Authentication-Results: i=1; imf22.hostedemail.com; dkim=pass header.d=google.com header.s=20230601 header.b=CDZI7lWp; spf=pass (imf22.hostedemail.com: domain of dvyukov@google.com designates 209.85.167.49 as permitted sender) smtp.mailfrom=dvyukov@google.com; dmarc=pass (policy=reject) header.from=google.com Received: by mail-lf1-f49.google.com with SMTP id 2adb3069b0e04-50ba8177c9fso4638e87.1 for ; Mon, 27 Nov 2023 01:38:25 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=20230601; t=1701077904; x=1701682704; 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=yXbJLlN8zN8yxyWwSZeLI9CkhU0ZX6ImmCRBdSzQVgU=; b=CDZI7lWpvET3FkPPGkkZudWZKCaoCq1UMTogx8AmnjMQZweqxSvLwLj6gkAxD58K8z P2dxQgDaQ2oTXreOIkEtvfHLnI+Em9gPwfMxuDIVDdO+I+FzMLecugQNU6rMZIfVUreb NvynmpCAo++mebVsVtcFN+0vdyoFxPunqzLAynEcjgksjVZ3hLMy2uQfpZMMxmu5hl/o mXl0KZ6KEGb2t7IOpfn9UviPcViVw6B47iuSngWNCubcAiAatMJq9powyezSDpUIh8aH XbTlCgekjr5d8S0JIsSfxvv+stzO55stH/1EdJpG767qPP+cP3LNS8MLQnaKaPf3DMXW AhcQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1701077904; x=1701682704; 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=yXbJLlN8zN8yxyWwSZeLI9CkhU0ZX6ImmCRBdSzQVgU=; b=Xu39QOOBqZ8SN98RpXliXDYEo7IflzSMEHomI6pH62gEUo7bzG2hzrslL899vSVxMV sOw0jvONvEGGG5Freg/IE4GAcyREvbpcMxE2KjZoNSeuNEyLjV6uBds8oZFo4XURdWaw b8XnN2ANqEouh5V8HRMpkdPp/e3Cruqbqw+vj+lMfFMTN6uk0EfFOWASVFWdBtthR7wa usVZz43h+sSN32PGADSpSLSGDnm9pK2bLiSUfAkEAgc/rJRYV1zh3oSowAph0oYJ6joK 0Bf1SWdybdoVzWmlwoX6aDGaaUHg5XS983oLnoLwKPFbdJSwufmnQYB/TYs7Gfg74cFZ zSZw== X-Gm-Message-State: AOJu0YxFRucJ0Rj7jl/jHaNESlyr7ShM2lJdODDY4+fNjzpjrzMPc3kA 8vu3Kjx9VpXCDMPUCseqzhbHJ6BkTXG39vMOHmJM/Q== X-Google-Smtp-Source: AGHT+IEa8BFGDd85yIJUytnb26EF+yw70QOFqlN7uMrSweTh3pkDV2IBJs24Go4gfKJMOLkxjBFq+Rwdz8KAkcc+FP0= X-Received: by 2002:a05:6512:281a:b0:50a:b7b3:19cd with SMTP id cf26-20020a056512281a00b0050ab7b319cdmr456358lfb.5.1701077903951; Mon, 27 Nov 2023 01:38:23 -0800 (PST) MIME-Version: 1.0 References: In-Reply-To: From: Dmitry Vyukov Date: Mon, 27 Nov 2023 10:38:11 +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-Stat-Signature: wd4etei4z4rybw9hypnzxhb9p3d6373i X-Rspamd-Server: rspam10 X-Rspamd-Queue-Id: 036EEC000E X-Rspam-User: X-HE-Tag: 1701077905-80961 X-HE-Meta: U2FsdGVkX1/yG1PK/TUeVAsucij9Z8eiPE2yyO3n3oUKsaYiHuWR9iYSUty5Mecb8k+wIjk3DDOOhKBOV0oiIkhaAPqOIx2CU3OWDJpEr9TTJlLF4rI0YqPrW16TPSzZSdb6kSlYEBmkIIEy83swG28NxLjbvaPlZqwuk7ByJL0rTi3bs8SN6crKcr/3jetmI9CSRsx/XcY3rb0BQNl7/hEr6b+VnatPIenIEgcG8o5QmcSj+Rjkv/xUMuk9nsaPrM5qsssoPEVdVPgRVZErBpQS9LwdjLYrarEIYyr9ipIus6oQdzZls2Vsntl9MLBX6g7rvEs2KQ+SxJiU/samuvx70GiewQwkQGNdJHrt7EVLisGVBQ0wroIJ1QVWmtsFZiuAydiwvhjJuqR5SfiDN2Sl2ftakBQjDuQ6WJG1/q9QxmUjzVgok5H6mRO6P5u0TrdKbqx3VR2gSTb91DE6M5pPB8GuYVf4S1/w+uTEjyRnr+ShQllO1ikunKxi8dExm1r5NFEon3647zbMS2B/TS+7MbGjol2+E7AFbRyHyBwBbxZOHkbDZ8htsQ45wm3wPq0nUyeZ3g6szhGkB/8loG/SuDsPuw8YUsWEypEYBwZzzFu6sZD4LcKxZZfqZfDgHjxcaX0lpcGjvTZMa/2S2eq56usbwchvX6OelaekUvFj453CrMbINrJVWlWKf/c4P5L8xpc4NE6XPhyYB0X5dUDxDw6GEvwHCgk2SQmliz/U0OQ5OR6sxU7kV/XLrhTqR8lopn2Id1PBss9buOKyoWeR+zeCCBdvIV9eygV1O6q27WUWiKRUcUXZ0f9vgNF6cSZa/Tv/3oIkqtOvyVgmOi1Bl95GlMewDp5K5muf2t1Vc38eNbH1+eVphWys7vhwsF8gxcKr6/lwh8/LuplkffYY0ic3fYK9szQysJ6JXg17hGJtwRZBdy7qfPXyuMvasAiKxd+EvKBq1hawLzb sY4wWRn+ U9wAS/VZpxDudPR5xFQrhuIEHn187Ucwj+Er9tIa4BvAFvRhVlHkZ46qANTMzLaebt9rr2N6X9UcWnDXTc1XeEl1EDssvHSPmngrgzEnG4gfddiXh5hkIE7ZZv8iTSTVp9Xdoy1e+1GePz6Me/FFmLa7v/cij5m3AwSTOdCs5v0q+CZwp5/IMNZFhFkkPLjpIQno+V5AXef13QQGkSsUefsxfvEQEfjcXqZSEGCSi7gg+Nt8V+xQ7d9XbGwNxMHGgUf5l5YZBr82fnTOOnjOykN1sHBMY3uIN4JCSkLR90pvfD/pPmsDBeVyjuMY03etL8MGwO8hGrXpNWzxLdE1EvZtrtka0pwatGR07 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 Mon, 27 Nov 2023 at 10:35, Juntong Deng wrote: > > On 2023/11/27 12:34, Dmitry Vyukov wrote: > > 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 > > > > > I think it would be better to use left shift and right shift because > dropping the last 3 bits would not affect the microsecond part and > would not affect the precision at all. > > In addition, 44 bits are enough to store the maximum value of the > displayable time 99999.999999 (5-bit seconds + 6-bit microseconds). > > 010110101111001100010000011110100011111111111111 (99999.999999) >> 3 > = 10110101111001100010000011110100011111111111 (44 bits) > > I will send the V3 patch. Agree. Modern compilers are smart enough to turn division/multiplication by pow-2 const into necessary shift, so we may not obfuscate the code. > >> +} > >> +#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 > >> >