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 mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id A8B8CC433EF for ; Tue, 2 Nov 2021 08:41:53 +0000 (UTC) Received: from kanga.kvack.org (kanga.kvack.org [205.233.56.17]) by mail.kernel.org (Postfix) with ESMTP id 5494361053 for ; Tue, 2 Nov 2021 08:41:53 +0000 (UTC) DMARC-Filter: OpenDMARC Filter v1.4.1 mail.kernel.org 5494361053 Authentication-Results: mail.kernel.org; dmarc=none (p=none dis=none) header.from=suse.cz Authentication-Results: mail.kernel.org; spf=pass smtp.mailfrom=kvack.org Received: by kanga.kvack.org (Postfix) id B682F6B0071; Tue, 2 Nov 2021 04:41:52 -0400 (EDT) Received: by kanga.kvack.org (Postfix, from userid 40) id B17DB6B0072; Tue, 2 Nov 2021 04:41:52 -0400 (EDT) X-Delivered-To: int-list-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix, from userid 63042) id 9E00694000A; Tue, 2 Nov 2021 04:41:52 -0400 (EDT) X-Delivered-To: linux-mm@kvack.org Received: from forelay.hostedemail.com (smtprelay0187.hostedemail.com [216.40.44.187]) by kanga.kvack.org (Postfix) with ESMTP id 900E56B0071 for ; Tue, 2 Nov 2021 04:41:52 -0400 (EDT) Received: from smtpin25.hostedemail.com (10.5.19.251.rfc1918.com [10.5.19.251]) by forelay03.hostedemail.com (Postfix) with ESMTP id 406E08249980 for ; Tue, 2 Nov 2021 08:41:52 +0000 (UTC) X-FDA: 78763347264.25.CB42E15 Received: from smtp-out2.suse.de (smtp-out2.suse.de [195.135.220.29]) by imf20.hostedemail.com (Postfix) with ESMTP id A795AD0000AB for ; Tue, 2 Nov 2021 08:41:43 +0000 (UTC) Received: from imap2.suse-dmz.suse.de (imap2.suse-dmz.suse.de [192.168.254.74]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature ECDSA (P-521) server-digest SHA512) (No client certificate requested) by smtp-out2.suse.de (Postfix) with ESMTPS id 7AD221FD78; Tue, 2 Nov 2021 08:41:50 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=suse.cz; s=susede2_rsa; t=1635842510; h=from:from:reply-to:date:date:message-id:message-id:to:to:cc:cc: mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=tz+vql88CgsF58vdIu35HL5zvxpH8YjJc4+0TvPpKZU=; b=H9YxqWEuNTYd76rLiYI4L2XWYeZpjWLmlKrUXU9juLdw0BiHN+rc/+2tqDR7Fy5Se8CEEs ckR+mYMKzMouG8AAdyCrXUQoGApmouZx3jOViMTAaaiQMvr3zWWYVivsmtKHsdKeJZ1O04 jEhFZ/seHwuQ3OclEt90swpZcmneaXo= DKIM-Signature: v=1; a=ed25519-sha256; c=relaxed/relaxed; d=suse.cz; s=susede2_ed25519; t=1635842510; h=from:from:reply-to:date:date:message-id:message-id:to:to:cc:cc: mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=tz+vql88CgsF58vdIu35HL5zvxpH8YjJc4+0TvPpKZU=; b=XT0uu/odAQtZWNn7poivWN7ZKPovW+GJIMttnv1upl52cpOvfSU2FT1dMPk/YkdsZKcob2 eB4XzNx8FV47N/DQ== Received: from imap2.suse-dmz.suse.de (imap2.suse-dmz.suse.de [192.168.254.74]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature ECDSA (P-521) server-digest SHA512) (No client certificate requested) by imap2.suse-dmz.suse.de (Postfix) with ESMTPS id 4EC1013B16; Tue, 2 Nov 2021 08:41:50 +0000 (UTC) Received: from dovecot-director2.suse.de ([192.168.254.65]) by imap2.suse-dmz.suse.de with ESMTPSA id HgZZEs75gGEFawAAMHmgww (envelope-from ); Tue, 02 Nov 2021 08:41:50 +0000 Message-ID: Date: Tue, 2 Nov 2021 09:41:50 +0100 MIME-Version: 1.0 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:91.0) Gecko/20100101 Thunderbird/91.2.1 Subject: Re: [PATCH] mm, slub: place the trace before freeing memory in kmem_cache_free() Content-Language: en-US To: John Hubbard , Yunfeng Ye , cl@linux.com, penberg@kernel.org, rientjes@google.com, iamjoonsoo.kim@lge.com, Andrew Morton , linux-mm@kvack.org, linux-kernel@vger.kernel.org Cc: wuxu.wu@huawei.com, Hewenliang References: <867f6da4-6d38-6435-3fbb-a2a3744029f1@huawei.com> From: Vlastimil Babka In-Reply-To: Content-Type: text/plain; charset=UTF-8 X-Rspamd-Server: rspam01 X-Rspamd-Queue-Id: A795AD0000AB X-Stat-Signature: 6ptyqy7ro8fg4duc465ix4ucuwehbnzj Authentication-Results: imf20.hostedemail.com; dkim=pass header.d=suse.cz header.s=susede2_rsa header.b=H9YxqWEu; dkim=pass header.d=suse.cz header.s=susede2_ed25519 header.b="XT0uu/od"; dmarc=none; spf=pass (imf20.hostedemail.com: domain of vbabka@suse.cz designates 195.135.220.29 as permitted sender) smtp.mailfrom=vbabka@suse.cz X-HE-Tag: 1635842503-376222 Content-Transfer-Encoding: quoted-printable 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: On 11/2/21 08:03, John Hubbard wrote: > On 10/30/21 03:11, Yunfeng Ye wrote: >> After the memory is freed, it may be allocated by other CPUs and has >> been recorded by trace. So the timing sequence of the memory tracing i= s >> inaccurate. >> >> For example, we expect the following timing sequeuce: >> >> =C2=A0=C2=A0=C2=A0=C2=A0 CPU 0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 CPU 1 >> >> =C2=A0=C2=A0 (1) alloc xxxxxx >> =C2=A0=C2=A0 (2) free=C2=A0 xxxxxx >> =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0 (3) alloc xxxxxx >> =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0 (4) free=C2=A0 xxxxxx >> >> However, the following timing sequence may occur: >> >> =C2=A0=C2=A0=C2=A0=C2=A0 CPU 0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 CPU 1 >> >> =C2=A0=C2=A0 (1) alloc xxxxxx >> =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0 (2) alloc xxxxxx >> =C2=A0=C2=A0 (3) free=C2=A0 xxxxxx >> =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0 (4) free=C2=A0 xxxxxx >> >> So place the trace before freeing memory in kmem_cache_free(). >=20 > Hi Yunfeng, >=20 > Like Muchun, I had some difficulty with the above description, but > now I think I get it. :) >=20 > In order to make it easier for others, how about this wording and subje= ct > line, instead: >=20 >=20 > mm, slub: emit the "free" trace report before freeing memory in > kmem_cache_free() >=20 > After the memory is freed, it can be immediately allocated by other > CPUs, before the "free" trace report has been emitted. This causes > inaccurate traces. >=20 > For example, if the following sequence of events occurs: >=20 > =C2=A0=C2=A0=C2=A0 CPU 0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 CPU 1 >=20 > =C2=A0 (1) alloc xxxxxx > =C2=A0 (2) free=C2=A0 xxxxxx > =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 = (3) alloc xxxxxx > =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 = (4) free=C2=A0 xxxxxx >=20 > ...then they will be inaccurately reported via tracing, so that they > appear to have happened in this order. This makes it look like CPU 1 > somehow managed to allocate mmemory that CPU 0 still had allocated for > itself: >=20 > =C2=A0=C2=A0=C2=A0 CPU 0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 CPU 1 >=20 > =C2=A0 (1) alloc xxxxxx > =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 = (2) alloc xxxxxx > =C2=A0 (3) free=C2=A0 xxxxxx > =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 = (4) free=C2=A0 xxxxxx >=20 > In order to avoid this, emit the "free xxxxxx" tracing report just > before the actual call to free the memory, instead of just after it. Agree, this wording is better. IIRC the same problem was fixed for mmap_lock trace ordering just recentl= y. >> Signed-off-by: Yunfeng Ye Reviewed-by: Vlastimil Babka