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 X-Spam-Level: X-Spam-Status: No, score=-5.8 required=3.0 tests=BAYES_00,DKIM_SIGNED, DKIM_VALID,DKIM_VALID_AU,HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI, SPF_HELO_NONE,SPF_PASS,URIBL_BLOCKED autolearn=no autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id 1D148C4320E for ; Wed, 1 Sep 2021 17:05:10 +0000 (UTC) Received: from kanga.kvack.org (kanga.kvack.org [205.233.56.17]) by mail.kernel.org (Postfix) with ESMTP id 639866108B for ; Wed, 1 Sep 2021 17:05:09 +0000 (UTC) DMARC-Filter: OpenDMARC Filter v1.4.1 mail.kernel.org 639866108B Authentication-Results: mail.kernel.org; dmarc=fail (p=none dis=none) header.from=oracle.com Authentication-Results: mail.kernel.org; spf=pass smtp.mailfrom=kvack.org Received: by kanga.kvack.org (Postfix) id B1011900002; Wed, 1 Sep 2021 13:05:08 -0400 (EDT) Received: by kanga.kvack.org (Postfix, from userid 40) id ABF288D0001; Wed, 1 Sep 2021 13:05:08 -0400 (EDT) X-Delivered-To: int-list-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix, from userid 63042) id 938F1900002; Wed, 1 Sep 2021 13:05:08 -0400 (EDT) X-Delivered-To: linux-mm@kvack.org Received: from forelay.hostedemail.com (smtprelay0060.hostedemail.com [216.40.44.60]) by kanga.kvack.org (Postfix) with ESMTP id 823BA8D0001 for ; Wed, 1 Sep 2021 13:05:08 -0400 (EDT) Received: from smtpin16.hostedemail.com (10.5.19.251.rfc1918.com [10.5.19.251]) by forelay01.hostedemail.com (Postfix) with ESMTP id 23D69181F3B4A for ; Wed, 1 Sep 2021 17:05:08 +0000 (UTC) X-FDA: 78539629896.16.6D97529 Received: from mx0a-00069f02.pphosted.com (mx0a-00069f02.pphosted.com [205.220.165.32]) by imf11.hostedemail.com (Postfix) with ESMTP id 72CDAF0000A8 for ; Wed, 1 Sep 2021 17:05:07 +0000 (UTC) Received: from pps.filterd (m0246617.ppops.net [127.0.0.1]) by mx0b-00069f02.pphosted.com (8.16.1.2/8.16.1.2) with SMTP id 181FnNnA001094; Wed, 1 Sep 2021 17:05:04 GMT DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=oracle.com; h=from : to : cc : subject : date : message-id : references : in-reply-to : content-type : content-id : content-transfer-encoding : mime-version; s=corp-2021-07-09; bh=IpRQxI0fzozfQH5VLfMtcIO3dlRZ7AykzbvzvRxsT+I=; b=IcRht0Mnhovz5dZ72MoxTPgnpyLstbGBfJiDsrjaWqVuFuYMfrnOawWE9A1i2G6EEC5/ tbHeUe5ImUdTKMRL+KwjF8yiEIgaM5LYwzDQSeYDSko24FbNlLGRQ/pTwiBFLcz74bKv QIR5W0qaU5Dg2KSJgpo32I/fDAloMzZ1+emN5E1vq6hU5Dh9DV2oqqVGOOHynzsqXt+W jyH79a3HMWvuXFwiTgN9r69Hbo4w2i7fej3GyJXzwfqgZFXWg2Z1bAs4MFgNoFaNKWBM P6sy1sYToUfUZ2baA74Ms6Mhy6q+2bmw7Ig/5CSo5n0l0MwJMpw3PPYUSWwOJBDE4YCk GQ== DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=oracle.com; h=from : to : cc : subject : date : message-id : references : in-reply-to : content-type : content-id : content-transfer-encoding : mime-version; s=corp-2020-01-29; bh=IpRQxI0fzozfQH5VLfMtcIO3dlRZ7AykzbvzvRxsT+I=; b=yP+DZMs5iiSJg60FjOhkQGe+8R9C+pW9pB9MnOPenzKC1kN8htYCpSGJ7gLaIKapSRmx H0AoXOG1hnArptB2BzLwInGbqv+cvXE5ilyF6bfL5Ixhb6JrmXxlfR6auguEXm3RNFWJ MnG4deNivyzz+yg1VgZVv5zHpocmNaIwnHW1OsLbVJ8w9wpKJ9cFmM0P/Lovq+HhZYNe blEHhzwtS9zWSEv9tyM9mdKJhMoRVjlnMzr4t5o3+nxfyvrQCkd8LyB9oDxvJre+9wsi m2wU/9EMmbnaRxnu7Z+TndD7dcIrlM/1qtPGhmc0qGGdref+eTaD4xlpI7xTLz3ABKWE xw== Received: from aserp3020.oracle.com (aserp3020.oracle.com [141.146.126.70]) by mx0b-00069f02.pphosted.com with ESMTP id 3asf66ncsw-1 (version=TLSv1.2 cipher=ECDHE-RSA-AES256-GCM-SHA384 bits=256 verify=OK); Wed, 01 Sep 2021 17:05:04 +0000 Received: from pps.filterd (aserp3020.oracle.com [127.0.0.1]) by aserp3020.oracle.com (8.16.0.42/8.16.0.42) with SMTP id 181Gtf6I143674; Wed, 1 Sep 2021 17:05:02 GMT Received: from nam10-mw2-obe.outbound.protection.outlook.com (mail-mw2nam10lp2107.outbound.protection.outlook.com [104.47.55.107]) by aserp3020.oracle.com with ESMTP id 3aqcy6xkv3-1 (version=TLSv1.2 cipher=ECDHE-RSA-AES256-GCM-SHA384 bits=256 verify=OK); Wed, 01 Sep 2021 17:05:02 +0000 ARC-Seal: i=1; a=rsa-sha256; s=arcselector9901; d=microsoft.com; cv=none; b=oYM5WkfC0wRrjkibEH3dAPYm8wRsginpMG/5DA0NZjyOj7irLwkuqj/wrLndkXyhrpoA440DB2KC2AuwjYHKa49saTIOZ+9EcDIYpN15m0hvFsjHuT75Fq7bXKegs3qsGBhh2rDlgpUttMAP5HjznirC3y+2tY6bPZRYQjSuP7lDRmADvv+ivhzcvfpwB7XJdDhxzue5gI4Oz002DPFQeo+RaT9JRJvB6/AI4fWN/JpaurSJMiv5eMjckfLLVOp8D8swLr4C0qdx7nXi2z+A1ZJfc5YCAKabwdKcrB71CNN55qcAYY4D6bokabnYPIQ3BbmsseGHiDZwYFVwmBYmjg== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=microsoft.com; s=arcselector9901; h=From:Date:Subject:Message-ID:Content-Type:MIME-Version; bh=IpRQxI0fzozfQH5VLfMtcIO3dlRZ7AykzbvzvRxsT+I=; b=nBcI4OdzTFNqeRLy/xUdZxxxaHvsHEMwEhx5Pz21Zrzf1mest2fPKw2gUr5dwLz3+E8xOFyuqVI+jF1wxJzs6QQJ/c4G54VqQEQq+WnAOVGMaRd10TDN8ZPdWIrQHQj7ELoUctW8FpJ7BDscCiuXPC88x13+SzX65qlTT0zGvLfD7w8LjUsYyzG9E+iwsbr8EOhbCyZHM0OrN0e8dfp5Qb+H+druHr1UEJ4uDkGTSTMmDNh6iRp7E3Jum7jzP6dUdfAvFVDGomtyS5Gtk3YoMCg/8Ip5VN+IK//l+SYstZ72gMq8PfFC3W3Q5VsVxJW2WuRwmaPOSjW8pC6uYECfMQ== ARC-Authentication-Results: i=1; mx.microsoft.com 1; spf=pass smtp.mailfrom=oracle.com; dmarc=pass action=none header.from=oracle.com; dkim=pass header.d=oracle.com; arc=none DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=oracle.onmicrosoft.com; s=selector2-oracle-onmicrosoft-com; h=From:Date:Subject:Message-ID:Content-Type:MIME-Version:X-MS-Exchange-SenderADCheck; bh=IpRQxI0fzozfQH5VLfMtcIO3dlRZ7AykzbvzvRxsT+I=; b=geucBJS72Kom8KpkAfYqojoaGeKgPPwZdjnfCyz9WHuXffXDk+xAODJaU3eQs/zKYKLeao9zTwKPN/KkWX8dCwHqU9689LWE65Fo3dA2JEy8C2c4gbigfCUhQyK7zVVrUiaSWtYAMQKsRWW92I4IqlkEQNJGyoT+CeF5eLpIBdk= Received: from DM6PR10MB4380.namprd10.prod.outlook.com (2603:10b6:5:223::19) by DS7PR10MB5183.namprd10.prod.outlook.com (2603:10b6:5:3a8::24) with Microsoft SMTP Server (version=TLS1_2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id 15.20.4478.17; Wed, 1 Sep 2021 17:05:00 +0000 Received: from DM6PR10MB4380.namprd10.prod.outlook.com ([fe80::f4b1:d890:7745:30a3]) by DM6PR10MB4380.namprd10.prod.outlook.com ([fe80::f4b1:d890:7745:30a3%4]) with mapi id 15.20.4478.020; Wed, 1 Sep 2021 17:05:00 +0000 From: Liam Howlett To: Vlastimil Babka CC: "linux-mm@kvack.org" , Michel Lespinasse Subject: Re: Strange mmap_lock tracepoint Thread-Topic: Strange mmap_lock tracepoint Thread-Index: AQHXnqhh7VimgmVH/ESa/cE4sY7tPquPAXcAgABoJ4A= Date: Wed, 1 Sep 2021 17:05:00 +0000 Message-ID: <20210901170447.fcqdnw43q7cmamzu@revolver> References: <20210831203959.lwofr24z63wjsgkc@revolver> <1585872a-1562-c74a-b686-e0051fa75cda@suse.cz> In-Reply-To: <1585872a-1562-c74a-b686-e0051fa75cda@suse.cz> Accept-Language: en-US Content-Language: en-US X-MS-Has-Attach: X-MS-TNEF-Correlator: x-ms-publictraffictype: Email x-ms-office365-filtering-correlation-id: 503457ec-c6b5-4079-d5d0-08d96d6aa20e x-ms-traffictypediagnostic: DS7PR10MB5183: x-microsoft-antispam-prvs: x-ms-oob-tlc-oobclassifiers: OLM:10000; x-ms-exchange-senderadcheck: 1 x-ms-exchange-antispam-relay: 0 x-microsoft-antispam: BCL:0; x-microsoft-antispam-message-info: 2NuoSqti7El8L0grTu0RH8tjqpMRni5ynTB/ibbMZDgIBsTfs+bxWpKFxWJxIMKElK6CM2FDe88a5s96JkaTC30lKzor73waY2MkVZ5f+GW64Fm6YcUh00DUTfKKHIcG7yC8HEmdTwBP1U+c5PQO4nIT9gEF1r+h4hAbuncWkljjIvNP9vM2Ev7HE9mynW7q3toqqLBX8sQmY+n6LYqOpvGNyu+asj9uHeZfClG/fvVGqxFBunT9upFQxp7Bh19fA/oNjT280T67qGupbxXCc1X+0s/HE4SFQcxOiJNOuUBC24bduXWtRGS5sqe8Gsgclt5wPf6yhAfaaZVBAgdKN8Q63a/fSG222SphjoL8FsXaZEyIUay2OlTKkXAwr2G0b+gTn4RFRK2KzNXEi2m73un8CX8gOwBu7tkn9jfGmd1sN/lbqNXsIifHBqC5GYVHAr3aWHkWsB/ftyjoAvrVcLlBW21v2bROk+LVAxnruK1fCFdA2Q+QtlE1gz1Pl+yx8nxoDa8IP1PqG4XpNFx6TTYZ3dVdNnO5Q/i2fqAM9JP7ghUYa24ohHM4QBcQ6Xq3LUW1CQStfCgbqxGBZva0aif3DBg34PH4Qmp0UsYbSzI1+HEi96OU2DMS8B/2WNCJAmceIiBwjwB37VG7d5H9md21g+YHrI4mfGu0Cdt07QrmqTQhiVfMpa8415Yroj6W/+drjS5RkjUwqhMqkwIrVQ== x-forefront-antispam-report: CIP:255.255.255.255;CTRY:;LANG:en;SCL:1;SRV:;IPV:NLI;SFV:NSPM;H:DM6PR10MB4380.namprd10.prod.outlook.com;PTR:;CAT:NONE;SFS:(7916004)(346002)(376002)(39860400002)(136003)(396003)(366004)(9686003)(71200400001)(76116006)(186003)(2906002)(26005)(91956017)(6512007)(66446008)(6486002)(64756008)(316002)(66476007)(4326008)(44832011)(54906003)(66556008)(1076003)(66946007)(5660300002)(53546011)(33716001)(83380400001)(122000001)(8936002)(7116003)(30864003)(38100700002)(6916009)(478600001)(6506007)(8676002)(86362001)(38070700005);DIR:OUT;SFP:1101; x-ms-exchange-antispam-messagedata-chunkcount: 1 x-ms-exchange-antispam-messagedata-0: =?us-ascii?Q?g8lUP/DGy8g807Nho3F74BL+khcB03PhceSgkVA/9waYMzMmMwvhOnWPkRhB?= =?us-ascii?Q?jk4XqQOmcrfmUDz7S8Yo11LQbpVsK1Mua6qFICLu9fBqa2QEGkKJqIq/gIkI?= =?us-ascii?Q?9/WTwCQ8gF6yjm3OmcUFP9nNGCyNWIUnQ6cyfFBF89CwnXvJ9n8aVcnKnPy+?= =?us-ascii?Q?4K7SCgrAHAGHnLO3ukYG5/2HtnwgpTOQrOr0dTSJNRea+m/1VmRDcgcYF5X2?= =?us-ascii?Q?0FFo1Dv0cqMNCqtfn+DldJeUMR4TAogqbMI+WcGWvrkt/Aodwgk+UFApdrMH?= =?us-ascii?Q?gtffjU4SIWMSZEkRXyIzNCvYnuOeXLzoG91m3JiUSiac1GvXheQnoFF7RVBU?= =?us-ascii?Q?925niBrnzYNtNpZCpWWX71T8YVDZZdpxadbxY9cnOBOgLqHBCOdi9UK62CK8?= =?us-ascii?Q?jbCPYG3rVpfH/e6ihFMuXttVZ4KyCBev9DfPcBI/DXTNBTnppb+4LBeEAr9d?= =?us-ascii?Q?ZoLLVZOPrPfYqli9jrcQMF3zwwYPGwUOxZpzgBizE7IevAzMm3Y0nzOIzSIJ?= =?us-ascii?Q?XsmxN/H04DVwYlSS+Na3bVZEdGDe8RyhlioYkcDUoHzd662y4ddeJZX5npOj?= =?us-ascii?Q?bB5S1YUTjpO1PiXWKQeY1W5oe2sBu86skASphlkfHOSjf6VfHGOFV+HSATNt?= =?us-ascii?Q?EPxzmsDP3PNoSifBav5XkBAQXTLQDLWnYG2VdjpspSzMZxckXCHX/YnOgX6J?= =?us-ascii?Q?HnJxddotEHuZMT4vQ6sWo4+JtXrWPc6KiugZhcScpl1aN+TXOojMNM6ZZ06b?= =?us-ascii?Q?gqqTPRt3DYNOaF77NjseY5uHQsv+7GQD1ct3YT+Mf+AIRyo3D3JSA2dQWfsK?= =?us-ascii?Q?8pEHAoBx0Qzihlc6qhIthb0m/0AbuHbOMIZXQz/omIHWgLYNTCdr8hzuwP4E?= =?us-ascii?Q?goJeDLPi2K7EkdEeMnoutNSWXRXxc4JzOGFEO9WepuNfa82DolvwfPxRe+p+?= =?us-ascii?Q?HCQqhQickUbu6ndpC2G65zV+jC6PA9Om2IYL9YONsi35+HoWbVcrfXXoLM3x?= =?us-ascii?Q?2mb+s2PT0+hlULqdkJbXaPg/wKhIYZ5dcUMf1zNfid7N5QgjFwZavpuYXzkr?= =?us-ascii?Q?ohQx75MqgfQholeLYC4ltCxqbjcoFi36g0/uur5xAHQhKQihWcRyFUHLuWQs?= =?us-ascii?Q?EDRtHOevJGHJARlOjEWh+qlnuuZeuFbPS1pRsKFbKQqYCNQ8+YX4RP8jIiEt?= =?us-ascii?Q?wuJGT9h5zAeGfoMvNCkr71xpbtSWjN8Gx7noCoXess6LEPZksmm8JXu3XZcl?= =?us-ascii?Q?ie6mYfmmdGipvW4QprzsnZdrjl4qQBglnno2RMiK5y0TSkat4hPzAcb8RvaF?= =?us-ascii?Q?T2rSF8/aegSzDX68MwtSX7pE?= x-ms-exchange-transport-forked: True Content-Type: text/plain; charset="us-ascii" Content-ID: Content-Transfer-Encoding: quoted-printable MIME-Version: 1.0 X-OriginatorOrg: oracle.com X-MS-Exchange-CrossTenant-AuthAs: Internal X-MS-Exchange-CrossTenant-AuthSource: DM6PR10MB4380.namprd10.prod.outlook.com X-MS-Exchange-CrossTenant-Network-Message-Id: 503457ec-c6b5-4079-d5d0-08d96d6aa20e X-MS-Exchange-CrossTenant-originalarrivaltime: 01 Sep 2021 17:05:00.2039 (UTC) X-MS-Exchange-CrossTenant-fromentityheader: Hosted X-MS-Exchange-CrossTenant-id: 4e2c6054-71cb-48f1-bd6c-3a9705aca71b X-MS-Exchange-CrossTenant-mailboxtype: HOSTED X-MS-Exchange-CrossTenant-userprincipalname: f+9opAV/slPlh6KPTVboSO+JwZLBNOl3iLf8UX49UnXwTPbNVuaK36mU50QwxbTgnuzkFidzYEj4cwupBN360g== X-MS-Exchange-Transport-CrossTenantHeadersStamped: DS7PR10MB5183 X-Proofpoint-Virus-Version: vendor=nai engine=6300 definitions=10094 signatures=668682 X-Proofpoint-Spam-Details: rule=notspam policy=default score=0 adultscore=0 suspectscore=0 phishscore=0 mlxscore=0 malwarescore=0 mlxlogscore=626 bulkscore=0 spamscore=0 classifier=spam adjust=0 reason=mlx scancount=1 engine=8.12.0-2107140000 definitions=main-2109010097 X-Proofpoint-GUID: sKQ6_5dzbc7ZsCtXXXFrQzNfVPSW6mLi X-Proofpoint-ORIG-GUID: sKQ6_5dzbc7ZsCtXXXFrQzNfVPSW6mLi Authentication-Results: imf11.hostedemail.com; dkim=pass header.d=oracle.com header.s=corp-2021-07-09 header.b=IcRht0Mn; dkim=pass header.d=oracle.com header.s=corp-2020-01-29 header.b=yP+DZMs5; dkim=pass header.d=oracle.onmicrosoft.com header.s=selector2-oracle-onmicrosoft-com header.b=geucBJS7; spf=none (imf11.hostedemail.com: domain of liam.howlett@oracle.com has no SPF policy when checking 205.220.165.32) smtp.mailfrom=liam.howlett@oracle.com; dmarc=pass (policy=none) header.from=oracle.com X-Rspamd-Server: rspam05 X-Rspamd-Queue-Id: 72CDAF0000A8 X-Stat-Signature: qwh1ckzpcn46nb4cqw7hymw8zudsnoro X-HE-Tag: 1630515907-891160 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: * Vlastimil Babka [210901 06:52]: > On 8/31/21 22:40, Liam Howlett wrote: > >=20 > > Hello, > >=20 > > I've been trying to trace the mmap_lock calls using tracepoints and > > captured this behaviour which I cannot explain. This was with the mapl= e > > tree v2 patches running ebizzy with multiple threads in an x86_64 KVM > > using 8 virtual CPUs. > >=20 > > AFAICT, there are zero callers that use the mmap_lock directly besides = a > > prefetchw(&mm->mmap_lock); > >=20 > >=20 > > ebizzy-803 [000] .... 5376.655366: lock_release: 0000000= 0de8cf25e lock > > ebizzy-803 [000] .... 5376.655366: lock_release: 0000000= 0b5e38448 ptlock_ptr(page) > > ebizzy-803 [000] .... 5376.655367: lock_release: 0000000= 06b581afd &mm->mmap_lock > > ebizzy-803 [000] .... 5376.655367: mmap_lock_released: m= m=3D000000001de7b122 memcg_path=3D write=3Dfalse > > =20 > > ebizzy-803 [000] .... 5376.655369: mmap_lock_start_locki= ng: mm=3D000000001de7b122 memcg_path=3D write=3Dfalse > > =20 > > ebizzy-803 [000] .... 5376.655369: mmap_lock_acquire_ret= urned: mm=3D000000001de7b122 memcg_path=3D write=3Dfalse success=3Dfalse > > =20 > > ebizzy-803 [000] .... 5376.655369: mmap_lock_start_locki= ng: mm=3D000000001de7b122 memcg_path=3D write=3Dfalse >=20 > I was thinking khugepaged interference, but this seems to be a system-wid= e > tracing (judging from -0) so you would see khugepaged too, right? Correct. All calls will go through Michel's tracepoints from what I can tell. >=20 > In the other hand it seems strange to have a long list of just cpu 0 here= . > Are other CPU's missing or just the interleaving is imperfect because > timestamps are not perfectly in sync between cpus, and in fact there was > another CPU who took the lock? Yes, it could be the clock. I had used the default clock which is local to CPUs. I was looking for documentation in 'time stamp' but should have looked for 'clock'. I've re-run the test with counter, which should remove the potential of incorrect ordering. I've also imported into a spreadsheet and sorted by the counter to ensure there isn't interleaving of printing causing issues. This is why the output below has a slightly different whitespace than the original. ebizzy-1437 [003] .... 83650150 : mmap_lock_released: mm=3D00000000ce5bd= 903 memcg_path=3D write=3Dfalse ebizzy-1437 [003] .... 83650157 : mmap_lock_start_locking: mm=3D00000000= ce5bd903 memcg_path=3D write=3Dfalse ebizzy-1437 [003] .... 83650158 : mmap_lock_acquire_returned: mm=3D00000= 000ce5bd903 memcg_path=3D write=3Dfalse success=3Dfalse ebizzy-1437 [003] .... 83650159 : mmap_lock_start_locking: mm=3D00000000= ce5bd903 memcg_path=3D write=3Dfalse ebizzy-1437 [003] .... 83650160 : lock_acquire: 0000000055bc357b read &m= m->mmap_lock ebizzy-1437 [003] d... 83650161 : lock_acquire: 00000000b3904b60 &sem->w= ait_lock ebizzy-1437 [003] d... 83650163 : lock_release: 00000000b3904b60 &sem->w= ait_lock ebizzy-1437 [003] d... 83650164 : lock_acquire: 00000000b5963f30 &rq->__= lock ebizzy-1437 [003] d... 83650168 : lock_acquire: 000000002d23d506 read rc= u_read_lock ebizzy-1437 [003] d... 83650169 : lock_release: 000000002d23d506 rcu_rea= d_lock ebizzy-1437 [003] d... 83650171 : lock_acquire: 000000002d23d506 read rc= u_read_lock ebizzy-1437 [003] d... 83650173 : lock_release: 000000002d23d506 rcu_rea= d_lock ebizzy-1437 [003] d... 83650174 : lock_acquire: 000000002d23d506 read rc= u_read_lock ebizzy-1437 [003] d... 83650175 : lock_release: 000000002d23d506 rcu_rea= d_lock ebizzy-1437 [003] d... 83650178 : lock_release: 00000000b5963f30 &rq->__= lock -0 [003] d... 83650181 : lock_acquire: 00000000b5963f30 &rq->__= lock -0 [003] d... 83650182 : lock_release: 00000000b5963f30 &rq->__= lock -0 [003] d... 83650183 : lock_acquire: 00000000b152519a read tk= _core.seq.seqcount -0 [003] d... 83650184 : lock_release: 00000000b152519a tk_core= .seq.seqcount -0 [003] d... 83650185 : lock_acquire: 00000000f5623f3e read ji= ffies_seq.seqcount -0 [003] d... 83650186 : lock_release: 00000000f5623f3e jiffies= _seq.seqcount -0 [003] d... 83650187 : lock_acquire: 000000006705bb4e &base->= lock -0 [003] d... 83650188 : lock_release: 000000006705bb4e &base->= lock -0 [003] d... 83650189 : lock_acquire: 0000000009614e04 hrtimer= _bases.lock -0 [003] d... 83650190 : lock_release: 0000000009614e04 hrtimer= _bases.lock -0 [003] d... 83650191 : lock_acquire: 00000000b152519a read tk= _core.seq.seqcount -0 [003] d... 83650192 : lock_release: 00000000b152519a tk_core= .seq.seqcount -0 [003] d... 83650193 : lock_acquire: 0000000009614e04 hrtimer= _bases.lock -0 [003] d... 83650194 : lock_acquire: 00000000b152519a read tk= _core.seq.seqcount -0 [003] d... 83650195 : lock_release: 00000000b152519a tk_core= .seq.seqcount -0 [003] d... 83650196 : lock_acquire: 00000000b152519a read tk= _core.seq.seqcount -0 [003] d... 83650197 : lock_release: 00000000b152519a tk_core= .seq.seqcount -0 [003] d... 83650198 : lock_release: 0000000009614e04 hrtimer= _bases.lock -0 [003] d.h. 83651382 : lock_acquire: 00000000b152519a read tk= _core.seq.seqcount -0 [003] d.h. 83651386 : lock_release: 00000000b152519a tk_core= .seq.seqcount -0 [003] d.h. 83651391 : lock_acquire: 00000000b5963f30 &rq->__= lock -0 [003] dNh. 83651403 : lock_release: 00000000b5963f30 &rq->__= lock -0 [003] dN.. 83651406 : lock_acquire: 00000000b152519a read tk= _core.seq.seqcount -0 [003] dN.. 83651409 : lock_release: 00000000b152519a tk_core= .seq.seqcount -0 [003] dN.. 83651411 : lock_acquire: 0000000009614e04 hrtimer= _bases.lock -0 [003] dN.. 83651415 : lock_acquire: 00000000b152519a read tk= _core.seq.seqcount -0 [003] dN.. 83651417 : lock_release: 00000000b152519a tk_core= .seq.seqcount -0 [003] dN.. 83651427 : lock_release: 0000000009614e04 hrtimer= _bases.lock -0 [003] dN.. 83651429 : lock_acquire: 0000000009614e04 hrtimer= _bases.lock -0 [003] dN.. 83651431 : lock_acquire: 00000000b152519a read tk= _core.seq.seqcount -0 [003] dN.. 83651433 : lock_release: 00000000b152519a tk_core= .seq.seqcount -0 [003] dN.. 83651441 : lock_release: 0000000009614e04 hrtimer= _bases.lock -0 [003] dN.. 83651443 : lock_acquire: 00000000b5963f30 &rq->__= lock -0 [003] d... 83651448 : lock_release: 00000000b5963f30 &rq->__= lock ebizzy-1437 [003] d... 83651453 : lock_acquire: 00000000b5963f30 &rq->__= lock ebizzy-1437 [003] d... 83651455 : lock_release: 00000000b5963f30 &rq->__= lock ebizzy-1437 [003] .... 83651458 : mmap_lock_acquire_returned: mm=3D00000= 000ce5bd903 memcg_path=3D write=3Dfalse success=3Dtrue ebizzy-1437 [003] .... 83651462 : lock_acquire: 000000005ada5d35 fs_recl= aim ebizzy-1437 [003] .... 83651464 : lock_acquire: 000000009ff6ca04 mmu_not= ifier_invalidate_range_start ebizzy-1437 [003] .... 83651466 : lock_release: 000000009ff6ca04 mmu_not= ifier_invalidate_range_start ebizzy-1437 [003] .... 83651467 : lock_release: 000000005ada5d35 fs_recl= aim ebizzy-1437 [003] d... 83651470 : lock_acquire: 0000000002c996e9 lock ebizzy-1437 [003] d... 83651472 : lock_release: 0000000002c996e9 lock ebizzy-1437 [003] .... 83651475 : lock_acquire: 00000000aae3fceb ptlock_= ptr(page) ebizzy-1437 [003] .... 83651476 : lock_acquire: 0000000064812dba lock ebizzy-1437 [003] .... 83651477 : lock_release: 0000000064812dba lock ebizzy-1437 [003] .... 83651478 : lock_release: 00000000aae3fceb ptlock_= ptr(page) ebizzy-1437 [003] .... 83651479 : lock_release: 0000000055bc357b &mm->mm= ap_lock ebizzy-1437 [003] .... 83651480 : mmap_lock_released: mm=3D00000000ce5bd= 903 memcg_path=3D write=3Dfalse ebizzy-1437 [003] .... 83651489 : mmap_lock_start_locking: mm=3D00000000= ce5bd903 memcg_path=3D write=3Dfalse ebizzy-1437 [003] .... 83651491 : mmap_lock_acquire_returned: mm=3D00000= 000ce5bd903 memcg_path=3D write=3Dfalse success=3Dfalse ebizzy-1437 [003] .... 83651492 : mmap_lock_start_locking: mm=3D00000000= ce5bd903 memcg_path=3D write=3Dfalse ebizzy-1437 [003] .... 83651494 : lock_acquire: 0000000055bc357b read &m= m->mmap_lock ebizzy-1437 [003] d... 83651496 : lock_acquire: 00000000b3904b60 &sem->w= ait_lock ebizzy-1437 [003] d... 83651497 : lock_release: 00000000b3904b60 &sem->w= ait_lock ebizzy-1437 [003] d... 83651499 : lock_acquire: 00000000b5963f30 &rq->__= lock ebizzy-1437 [003] d... 83651501 : lock_acquire: 000000002d23d506 read rc= u_read_lock ebizzy-1437 [003] d... 83651504 : lock_release: 000000002d23d506 rcu_rea= d_lock ebizzy-1437 [003] d... 83651505 : lock_acquire: 000000002d23d506 read rc= u_read_lock ebizzy-1437 [003] d... 83651507 : lock_release: 000000002d23d506 rcu_rea= d_lock ebizzy-1437 [003] d... 83651510 : lock_acquire: 000000002d23d506 read rc= u_read_lock ebizzy-1437 [003] d... 83651512 : lock_release: 000000002d23d506 rcu_rea= d_lock ebizzy-1437 [003] d... 83651515 : lock_release: 00000000b5963f30 &rq->__= lock -0 [003] d... 83651517 : lock_acquire: 00000000b5963f30 &rq->__= lock -0 [003] d... 83651520 : lock_release: 00000000b5963f30 &rq->__= lock Please note that this is now next-20210811 directly. No maple tree patches. As per the grouping of each thread, I don't really have an answer. There are places in the trace which do have different CPUs and threads running interleaved: ebizzy-1445 [000] .... 83693711 : lock_release: 0000000055bc357b &mm->mm= ap_lock ebizzy-1445 [000] .... 83693715 : mmap_lock_released: mm=3D00000000ce5bd= 903 memcg_path=3D write=3Dfalse ebizzy-1437 [003] .... 83693727 : mmap_lock_start_locking: mm=3D00000000= ce5bd903 memcg_path=3D write=3Dfalse ebizzy-1437 [003] .... 83693730 : lock_acquire: 0000000055bc357b try rea= d &mm->mmap_lock ebizzy-1437 [003] .... 83693733 : mmap_lock_acquire_returned: mm=3D00000= 000ce5bd903 memcg_path=3D write=3Dfalse success=3Dtrue ebizzy-1437 [003] .... 83693738 : lock_acquire: 000000005ada5d35 fs_recl= aim ebizzy-1437 [003] .... 83693742 : lock_acquire: 000000009ff6ca04 mmu_not= ifier_invalidate_range_start ebizzy-1445 [000] .... 83693743 : mmap_lock_start_locking: mm=3D00000000= ce5bd903 memcg_path=3D write=3Dfalse ebizzy-1437 [003] .... 83693747 : lock_release: 000000009ff6ca04 mmu_not= ifier_invalidate_range_start > > >=20 > > The following tracepoints were enabled: > > events/mmap_lock/enable > > events/lock/enable > >=20 > > My reading of the above trace is that the ebizzy thread dropped the loc= k > > and immediately attempted to reacquire and detected it was in contentio= n > > so the thread added itself to the list and went to sleep only to wake u= p > > and get the lock? >=20 > Which path does this mmap_read_trylock() followed by immediate > mmap_read_lock() anyway? I mean down_read() is implemented like this > internally, but that wouldn't generate these mmap_lock_ events. I think it's do_user_addr_fault()? >=20 > > Doesn't that mean the mmap_lock is _not_ contended? The lack of > > contention makes sense since there is no tracepoint of an attempt to > > acquire the lock between the dropping of the lock and the same MM wakin= g > > up to get the lock. > >=20 > > What is even stranger is if I change the value of _Q_PENDING_LOOPS from > > (1 << 9) to (1 << 10), the benchmark performs better. > >=20 > > From the above trace and the effects of the _Q_PENDING_LOOPS change, it > > looks like the lock is somehow remaining in a state that causes a > > failure to acquire the lock even when it is not held or contended? So the new log is with trace_clock set to counter with next-20210811 running ./ebizzy -m (only use mmap) on a KVM with 8 CPUs. Thanks, Liam=