From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1754673AbdEHOYB (ORCPT ); Mon, 8 May 2017 10:24:01 -0400 Received: from mx0a-00082601.pphosted.com ([67.231.145.42]:33401 "EHLO mx0a-00082601.pphosted.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1750985AbdEHOX6 (ORCPT ); Mon, 8 May 2017 10:23:58 -0400 Authentication-Results: vger.kernel.org; dkim=none (message not signed) header.d=none;vger.kernel.org; dmarc=none action=none header.from=fb.com; Subject: Re: Large latency on blk_queue_enter To: =?UTF-8?Q?Javier_Gonz=c3=a1lez?= References: <1656B440-3ECA-4F2B-B95C-418CF0F347E9@lightnvm.io> <20170508122738.GC5696@ming.t460p> <76E35BA3-FEC9-46D6-B36F-554F464FA9ED@lightnvm.io> CC: Ming Lei , Christoph Hellwig , "Dan Williams" , , "Linux Kernel Mailing List" From: Jens Axboe Message-ID: <661d4b67-cf0c-a703-331b-ce24d75e782d@fb.com> Date: Mon, 8 May 2017 08:23:36 -0600 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:45.0) Gecko/20100101 Thunderbird/45.8.0 MIME-Version: 1.0 In-Reply-To: Content-Type: text/plain; charset="windows-1252" Content-Transfer-Encoding: 8bit X-Originating-IP: [216.160.245.98] X-ClientProxiedBy: MWHPR01CA0045.prod.exchangelabs.com (10.172.172.159) To MWHPR15MB1197.namprd15.prod.outlook.com (10.175.2.139) X-MS-PublicTrafficType: Email X-MS-Office365-Filtering-Correlation-Id: 89972c03-f73a-4c2f-afbd-08d4961dd3c9 X-Microsoft-Antispam: UriScan:;BCL:0;PCL:0;RULEID:(22001)(201703131423075)(201703031133081);SRVR:MWHPR15MB1197; X-Microsoft-Exchange-Diagnostics: 1;MWHPR15MB1197;3:HO4IXBxeTpL3dSTRhkIIHYp5ECh5bCjSHraQWttGJqHUkhDbS9FVQ0CDD0Pbj3O3DmFcZxuE+yhwGVNhSVNn9jy2soVIcoVu45rBQbf0YaX19BWE594tYGYv0qG6ix4Wm9i53UkIDIruneFiSxDz3184g4KlS9uFp2vCuQD4NoWCucT5kL9ggQqlJecy8NZnYfqFU4MgxFOAWA11U97NXRTWSXr+Wl1N/1spBE1o08zVrJNSy4ZlKQ1k/zbb6J5o1A/R4wyX2pv8ZwFelWZzfZSxnV+fLWHXIk4Q6Eeh5jPb49H6caVv50Pb7ZtFhcBsmSis/Rjx8jY/m2EN6XUZJg==;25:SO5YoQPDL6Zug7BBZ25LwBhz2wXIuAzAsUc+ESlxE34Nc+teF6cGIzVrs+TGy+scExucNDNWZ6aCf8YOwv94dJmg9YAmJfAs0K/x6GnaXpmVLA40HOn8YrfxkDY/+l8mNttDUjS98ra2NC8kIVyoqQEBoSVKKGPUe+zdao75bjqp+6DjdPzzz88AE+du340PSRnBeJ4WKr233eAqJt+EWNazlxB7bl1BpthypBaUGqze/RDjOfA6GqvG/vl9jT5hSMcUHCz+xd9zUxtsoQlpoQvb11lUjbVjcFQPSGEqmsGdzg3zCL+NA5V5+T3vwzh+z/TnvVKc0+SQksdOilrhPeAu1eeO292SifHUnC62piZY6u6R20CrYum8C6y981T5ODWKg2G6+L/LVJKkkMkgBqgACpmuNJp47WQ3xHp5pPnTuH1V0aV/RyC0GFu6i34Zs6AWMQl32O0YhHrXJzoCIImtjLFSf921wqriCk4u+tw= X-Microsoft-Exchange-Diagnostics: 1;MWHPR15MB1197;31:D1gblAeumFiFRNbbcc5HEvQ61ZoN7qg/pMX1UZglkko22EEqNzAzAurexqgUr/unBC38wA2nQBOntO/7dcDVk1gkaE9SGNIdYjp98XJh0nsLJdRe4RWmevJx10o+sEpxhisd50PWvfu08xMvemX4BdeXDmNj2K/TNqL2/G9/aCio980bKcg3RvVeW2empP0P7Amr1Ab8hdKyPohhTHhe0Tuy6JHMKeR/87MH0iKAkK7twk7qKojBwFF1ehxMXrzmTWQYxDUzwz/Ok5KWeN7SjupD0B1iEVySJt4PlujSYk4=;20:tJUo7ohEkuRjtQnvlRSI1JTaQmyGkPM53I0cPURFJT1G+n3oVfTKUBqY8uAvQbXmB6uQcaQ8OEeeDrojUczSTVedmR7gHpS1sXpR0f8D1M5fnPh5kMedtQ8GRFzdV4GEhWONsT/MNgZCEypqZOHmhJcP2YBWEnOqPUFmapDeYmN8r1wgkHMC3S7O3LKTcxDHJU1nxJT33/9XlH8lW6qMux+z1FvJZ6QI5SS6DFJ1PtdoL5a+JO3ESkB9jGhyhrGzXtFwJzZUkQK/9k8vG+h9byo5sLmGTXFiPtHa3h5vkhUAi2HtCYt/YeTV5V0ISNfWpBcvtm+tGHzEO9kC1/2y+EEzUcXiDDxhq7qbs6HKXGtysJv47JPuMeqaPNARbMsUCExXIDiSRQ/9PdMgPIIexIRmj4Lyk6d4PGJDny7QTahw9TtVUk41Chj3dq0h/DnFNAje3i2LMOkbGxqzta6BMVSZJHHjyWFQsze8Edc3wQQOWyVg36oAiSmFRbi+TBX+ X-Microsoft-Antispam-PRVS: X-Exchange-Antispam-Report-Test: UriScan:(67672495146484); X-Exchange-Antispam-Report-CFA-Test: BCL:0;PCL:0;RULEID:(6040450)(601004)(2401047)(5005006)(8121501046)(3002001)(10201501046)(93006095)(93001095)(6041248)(201703131423075)(201702281528075)(201703061421075)(201703061406153)(20161123558100)(20161123555025)(20161123560025)(20161123564025)(20161123562025)(6072148);SRVR:MWHPR15MB1197;BCL:0;PCL:0;RULEID:;SRVR:MWHPR15MB1197; X-Microsoft-Exchange-Diagnostics: 1;MWHPR15MB1197;4:sO9q58rb/SoaGe0W/f7KODICzCceXBKfFVxBhofLTiue/SRefXw6o+xe7euAMk4dh/pwYmZB40RcQpi34dpjF7L/Ef6wNSQYvzkTY/7LEiDmECgOyqqOu0lfFhRnWXp7zirJlsVRiNo3vovmWQHaFWcY/13Og7ryYTkf4MqEIIRafYnJvRCTg+x43Lw/SoZ+C4WLZjmRkgZ27T8Z/TPEbpv3+wabWk+PwFjrvXUJeHBEdV31sGARw0Retw5DdM0pUM4IGQt3hVqQxu/pcM3X0P8vMrfWcocfjCFWnWszIsHKxb9yQK1PXZTwwuGqRNAQlE3AxWBVWSsYPnBOHE+FzO6u3KMRXtU78yrjZRN2gzJ1mW/tVvk+D5IoOHTdOmyDXjXnluTQYFU4SbviXGZaenc/s6nl/zA4Nm+PXIL5Of0IhoGdp3Gq6FVOlIgAhQSHa2LJliwnMa5gkTYzgUX6gIirQAmaSpNoCjYn5B1PnQmRs4rHwVYsynwwlrYVcD8pzo4U2gEhDcAQTv2xVgLkuUYoWuUvu7f63ntUhUpLVuQDzIHDOlB3MWoZ4yJU3R6i/sttbOQn1XfSbGr55ZDmp0GkJUf7XxD8lTUDtWxLL8vUjyio7diKyqSfhQMs1vkFYbzWmgPofGzGO2luBHDTHePQlokjvaUBekt6eg7iedYAvNTUQfUQmjw1h1QM3HxKeXfko+ITM7p8iUF0baE26hcADhmaAQ13w8NqjmkXfes2FkUAkONqAXisDOuaTckEMMVgs2SO7Ok364fFVQfsIVchpeZYHXuzjT/nWuIfQf4B83yASOfCjBxBlBskMAw2dtj8gUUhD+XeP0owKJPfrg== X-Forefront-PRVS: 0301360BF5 X-Forefront-Antispam-Report: SFV:NSPM;SFS:(10019020)(4630300001)(6009001)(6049001)(39450400003)(39850400002)(39410400002)(39840400002)(39400400002)(377454003)(24454002)(38730400002)(110136004)(33646002)(2870700001)(6916009)(6666003)(65956001)(42186005)(478600001)(31696002)(86362001)(50466002)(90366009)(36756003)(2906002)(53936002)(6246003)(83506001)(5660300001)(229853002)(77096006)(65806001)(65826007)(66066001)(6116002)(189998001)(2950100002)(3846002)(50986999)(54356999)(76176999)(64126003)(7736002)(93886004)(53546009)(47776003)(25786009)(6486002)(8676002)(117156002)(81166006)(4001350100001)(4326008)(305945005);DIR:OUT;SFP:1102;SCL:1;SRVR:MWHPR15MB1197;H:[192.168.1.154];FPR:;SPF:None;MLV:sfv;LANG:en; X-Microsoft-Exchange-Diagnostics: =?Windows-1252?Q?1;MWHPR15MB1197;23:Dgj/n6zlHA7eSzTLpcm62s1mFytFRQpne83bo?= =?Windows-1252?Q?lr2+kxHT/GdkEAL0H0Cw/d7/5xxbd/IAL6Mltzq6PPGxiUnv2xkCsEDz?= =?Windows-1252?Q?nGZLaV87nddFSJ+Z2/ONjNwZ6mpc60Nzvd2XEFkawmPZakmtwXqlgkn6?= =?Windows-1252?Q?ZStPk0GXxLiWXVbdRjrg9y9AYnzQEbMF+6KTIJEAm7VshF34GsyfU3CJ?= =?Windows-1252?Q?o3o89qSDpycGsuGcgBNIkAHmgYZkllqmhSwAzL4ue/UmMtbNXMS2HArr?= =?Windows-1252?Q?JoDREMYJIOsDWjEO3/UG4+SooPRpts+uJa2FbTgjDrhQIYSZjzeWz/T1?= =?Windows-1252?Q?7KRgFQPbd0JDp0SjfH+sqSojY7CpppmdCgKGHrr33v0SG5zvxquvUZ3a?= =?Windows-1252?Q?CITNYkLitVvUXikUMTGigS4Ab3fX/GIyns4IesTlOsRUywKon31whaC/?= =?Windows-1252?Q?wELtZBk57RRHqXMWs3L2gHOjU/p/VZN+p6xQ9/h33sYyJ8+NiIatnWgb?= =?Windows-1252?Q?qJQlyzELC3VCYF1wDcjP0notelVsom1e6U0yEPf5BM/Bk30ODntB/z3T?= =?Windows-1252?Q?XIbLPYQfvIo70D3OzLIaiQAg4twTPyp24Uh4qXXd9rphn+NcstjpWCeD?= =?Windows-1252?Q?4p+R2lgndiKovDMkKq/DQ6JkSyCm4Dexzmm3Imv8puBCIS8eVKmZgel3?= =?Windows-1252?Q?SkB7xBXUSQfmHP+rKvlihxyZhGbAIbvVwshH4g+LHrWvNWPq59/9NGQh?= =?Windows-1252?Q?SsYQ4jym8ggr3XSuuB81w+aGmanxTctVueaW1T/m/dOgnIf6CdNHizVD?= =?Windows-1252?Q?sJ8LV1KjB3JKtG+6wMMcJDI6zhrnMkV1oYbsdnPJaF0uvzYk1eoEkkqx?= =?Windows-1252?Q?GgIPn2oTltmzh41fjvw8YfEl484+2AGTMbfoR8MMaJ47G3bSY0BmfJbT?= =?Windows-1252?Q?36mRLIScQuliQV5O9InhEajhgRyhU77E/LLlh8DXQfOTQYUDXewbfXE/?= =?Windows-1252?Q?BIQTo9BgIYOcpPZIGFOKYI8nCsG+OkIabMDRzikiYx9GWIZjyfbQi5pF?= =?Windows-1252?Q?5+DFkhdUUzKFjTslWZ6Xpec+F4QoDS66ycsyLWepPwgqwFbCoUVfU95t?= =?Windows-1252?Q?iarBmuJhvrvJwOouiPiOgK0S8+QPy9EWWoC48lElPJhada4RyjcSxaGa?= =?Windows-1252?Q?UOwWvdqe/+cc/2IcXjRKUN3vtb6yYotVsMsqaFB/e3e+W+HmYpww5pVO?= =?Windows-1252?Q?xQlDR+owJie9swcqJvY1ta1JSD66yRGAprxRc6elGLZwS/+HijX7DYzN?= =?Windows-1252?Q?IC7DZqcnbVoaDSjDpil/Ted4OuNaPKBaAtKExTPunebrlWmKSYyCCAzk?= =?Windows-1252?Q?y3bRE6yVcmLpHq5YWvhzB7/BS/CllQzOLIL5PVZ9lY9eTu86QAzB8fPI?= =?Windows-1252?Q?2T+KzodOO6wJiw9yArA?= X-Microsoft-Exchange-Diagnostics: 1;MWHPR15MB1197;6:QYLuGmS3hC9qwAuUeyHTHYiRCIqNUWCLDo5HIto6ZPa7eszfkU4JVl/1kcw3YxGgfF4Zqanjb91vjyMikwP/r+QCa17Wx+ZZjHIJ0XhCvOTwrTVbiAB2v1Jh5F7zPHziZjNjLEzJxlt7qx146/MOpaWaL65gt8sfIjHgrCSiz/pjhNXdRfVQ2rJnol56zO5+SxDgn+GwaA336qGpmUUODZ5XcmI7Eak1xsodJ3s7bj1b+1/uTYayqg8TtpR6kvtHTiJ7b2tbRWV3Bc9VRAUaaB/Bq1aKhNH0YrfYn7WN/85E5qZfasdv9uiC024+DS68EELyTgo20esnqqsOtqoo41RbeUDF0NJ6gZE1Al6hC/hG+/MqNL1BL7L8TUo1l1kAeowPHWk+r96bTI+hJ7KIT4by+aFDmPY/mYgDSh6JnIhVc79Nh/UJqf/lqK3i0aqysAirMhOJNe1VZetSpVi451RleYGiPYVCAgz4u4D/1gOrUIRYSLiIWcoq4NZIFEYBkQFr2vskkqkUg5L2IfsBkA==;5:12HF7Uu/TZqsOrGQX2HeXh23YJKbRLdhoFskTBpUCVx5KTfcxiD3fkzXKn4cjxrplU/qG2WFGy0oxoB4OCAGMAUeqharrLMngnCzbqaeDUHPyL1Ivks6MGc4Qge6OBjFPAQJq2vkyAEs180U3xZFrw==;24:ChPpbfdhpgD+vd4jznVbjIh+LCfT14Km6NfkNZA8LUDtzWBOVDlHGgISqtERt9BXDEZDqK6yNwd1SbFfN23SVm13EO7k46GRS/D0n42zH28= SpamDiagnosticOutput: 1:99 SpamDiagnosticMetadata: NSPM X-Microsoft-Exchange-Diagnostics: 1;MWHPR15MB1197;7:23zLWJpK18rjLmBK2xRUBTJvxU3k5GaMDjjAj+Vbpg6Xl4Wppce1KuClcnI2KfAtewcTpS82vbedDj628KuFKckjQY4mMd2XoBbIN9h2JTUjQ4Ia/QoKmozEYfdcz6+lu7q66ysnK0ShgB+e5k43buX5HBTEy/83sr2yQRSrLKSxUUvLfaq8kuUuXh7Y3IN0IxlLrNLr/iqvVVTrGJBVGQCfyOLPHW3UF2Vk770jUXfc8F063iI3QNSngDJj15kPIwi/t3agMtOha83fgbPLSHBQzQuL1cm1bV4HKVZaWteZSQk51Am87s3jAGxx+saqm93nPVfpEfDi1o+5vez9VQ==;20:cUUTJV3vqJ+1qispEzfh/KViX+cc3BKg+ARN4hRttBnRvv4VV0LeuoofAzYrlarHDJkEKIimeLktwva2ZNU1RRX6ivc3ZNQrMjhmpmworIDpveMtcTzxJR+BnWdpALF/c9vD3dXumNxZwg4fRFkdXcacHhIzI1IUa8W5YFFjKmA= X-MS-Exchange-CrossTenant-OriginalArrivalTime: 08 May 2017 14:23:40.1926 (UTC) X-MS-Exchange-CrossTenant-FromEntityHeader: Hosted X-MS-Exchange-Transport-CrossTenantHeadersStamped: MWHPR15MB1197 X-OriginatorOrg: fb.com X-Proofpoint-Spam-Reason: safe X-FB-Internal: Safe X-Proofpoint-Virus-Version: vendor=fsecure engine=2.50.10432:,, definitions=2017-05-08_10:,, signatures=0 Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On 05/08/2017 08:20 AM, Javier González wrote: >> On 8 May 2017, at 16.13, Jens Axboe wrote: >> >> On 05/08/2017 07:44 AM, Javier González wrote: >>>> On 8 May 2017, at 14.27, Ming Lei wrote: >>>> >>>> On Mon, May 08, 2017 at 01:54:58PM +0200, Javier González wrote: >>>>> Hi, >>>>> >>>>> I find an unusual added latency(~20-30ms) on blk_queue_enter when >>>>> allocating a request directly from the NVMe driver through >>>>> nvme_alloc_request. I could use some help confirming that this is a bug >>>>> and not an expected side effect due to something else. >>>>> >>>>> I can reproduce this latency consistently on LightNVM when mixing I/O >>>>> from pblk and I/O sent through an ioctl using liblightnvm, but I don't >>>>> see anything on the LightNVM side that could impact the request >>>>> allocation. >>>>> >>>>> When I have a 100% read workload sent from pblk, the max. latency is >>>>> constant throughout several runs at ~80us (which is normal for the media >>>>> we are using at bs=4k, qd=1). All pblk I/Os reach the nvme_nvm_submit_io >>>>> function on lightnvm.c., which uses nvme_alloc_request. When we send a >>>>> command from user space through an ioctl, then the max latency goes up >>>>> to ~20-30ms. This happens independently from the actual command >>>>> (IN/OUT). I tracked down the added latency down to the call >>>>> percpu_ref_tryget_live in blk_queue_enter. Seems that the queue >>>>> reference counter is not released as it should through blk_queue_exit in >>>>> blk_mq_alloc_request. For reference, all ioctl I/Os reach the >>>>> nvme_nvm_submit_user_cmd on lightnvm.c >>>>> >>>>> Do you have any idea about why this might happen? I can dig more into >>>>> it, but first I wanted to make sure that I am not missing any obvious >>>>> assumption, which would explain the reference counter to be held for a >>>>> longer time. >>>> >>>> You need to check if the .q_usage_counter is working at atomic mode. >>>> This counter is initialized as atomic mode, and finally switchs to >>>> percpu mode via percpu_ref_switch_to_percpu() in blk_register_queue(). >>> >>> Thanks for commenting Ming. >>> >>> The .q_usage_counter is not working on atomic mode. The queue is >>> initialized normally through blk_register_queue() and the counter is >>> switched to percpu mode, as you mentioned. As I understand it, this is >>> how it should be, right? >> >> That is how it should be, yes. You're not running with any heavy >> debugging options, like lockdep or anything like that? > > No lockdep, KASAN, kmemleak or any of the other usual suspects. > > What's interesting is that it only happens when one of the I/Os comes > from user space through the ioctl. If I have several pblk instances on > the same device (which would end up allocating a new request in > parallel, potentially on the same core), the latency spike does not > trigger. > > I also tried to bind the read thread and the liblightnvm thread issuing > the ioctl to different cores, but it does not help... How do I reproduce this? Off the top of my head, and looking at the code, I have no idea what is going on here. -- Jens Axboe