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, HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI,NICE_REPLY_A,SPF_HELO_NONE, SPF_PASS,USER_AGENT_SANE_1 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 8242EC433E1 for ; Mon, 17 Aug 2020 18:24:11 +0000 (UTC) Received: from kanga.kvack.org (kanga.kvack.org [205.233.56.17]) by mail.kernel.org (Postfix) with ESMTP id 4C54F20716 for ; Mon, 17 Aug 2020 18:24:11 +0000 (UTC) DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 4C54F20716 Authentication-Results: mail.kernel.org; dmarc=none (p=none dis=none) header.from=mentor.com Authentication-Results: mail.kernel.org; spf=pass smtp.mailfrom=owner-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix) id BB3B66B0002; Mon, 17 Aug 2020 14:24:10 -0400 (EDT) Received: by kanga.kvack.org (Postfix, from userid 40) id B64B76B0005; Mon, 17 Aug 2020 14:24:10 -0400 (EDT) X-Delivered-To: int-list-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix, from userid 63042) id A7B8F6B0006; Mon, 17 Aug 2020 14:24:10 -0400 (EDT) X-Delivered-To: linux-mm@kvack.org Received: from forelay.hostedemail.com (smtprelay0209.hostedemail.com [216.40.44.209]) by kanga.kvack.org (Postfix) with ESMTP id 9171A6B0002 for ; Mon, 17 Aug 2020 14:24:10 -0400 (EDT) Received: from smtpin29.hostedemail.com (10.5.19.251.rfc1918.com [10.5.19.251]) by forelay02.hostedemail.com (Postfix) with ESMTP id 58D5A173087C for ; Mon, 17 Aug 2020 18:24:10 +0000 (UTC) X-FDA: 77160885060.29.bird55_33018e227018 Received: from filter.hostedemail.com (10.5.16.251.rfc1918.com [10.5.16.251]) by smtpin29.hostedemail.com (Postfix) with ESMTP id 2138118086CAB for ; Mon, 17 Aug 2020 18:24:10 +0000 (UTC) X-HE-Tag: bird55_33018e227018 X-Filterd-Recvd-Size: 5054 Received: from esa4.mentor.iphmx.com (esa4.mentor.iphmx.com [68.232.137.252]) by imf33.hostedemail.com (Postfix) with ESMTP for ; Mon, 17 Aug 2020 18:24:08 +0000 (UTC) IronPort-SDR: vf0i835fMNj7btpRwQYdCrsmxKGimFnaKL01HcgqbRYGNPttbdJwW8Rg3ln0lbPMniKs0jovAF JynMUqrGKJA4hQVcQ5cn9RTXcR4OQrpcw9IyyVrq0wUtMyvX3zrhqaMRetfN2+MRzwqYtxmvw6 8nxxt3MrzLgCKGya0HEziq/jYpEP/KFztbNbFervGED1lG+17TROu/1WHpMeUnGbKX3CO0ktvK r5q1mtVRlhr/bikXzDwaGgHBlxSoJQMORGUINh75EN3+beNe8Txc4h/omw/tU2n4XbSjOYRflU yUE= X-IronPort-AV: E=Sophos;i="5.76,324,1592899200"; d="scan'208";a="52111680" Received: from orw-gwy-01-in.mentorg.com ([192.94.38.165]) by esa4.mentor.iphmx.com with ESMTP; 17 Aug 2020 10:24:07 -0800 IronPort-SDR: ToVR6YUYiFLED4f7TyLPCb76YYE4RyQYIkb/RVKa+y2NJZJJc9Br2Nbxt7IxP04SB4VuZZ8qYz qFUWSxePybGpHXN0v3Z0GlxrAt+S8x2hyXQKXX+sZPnaV9MOcCl6NB9op+D/hXRv/9zl65mk82 95NsJRREfN0cr3z+uR4c2PY4WxBaf8jPFTwGNuCRjSKgEJb76NRmDcMluBPDOJNW5i4p2oA+jM ofaL9IHmaArtglsagpqQ+h3gx84cktLw5RmkkZ1B55lDuo8P2eGY4DpZ9Sq8dLmJPlIl8ato+Y s7U= Subject: Re: PROBLEM: Long Workqueue delays. To: Greg KH CC: , , , "Resch Carsten (CM/ESO6)" , "Rosca, Eugeniu (ADITG/ESB)" References: <71aafe68-7fe0-6b77-ea8e-83edd3f16c8d@mentor.com> <20200817115744.GA3985908@kroah.com> From: Jim Baxter Message-ID: <57a7841d-86e3-b6df-1488-a252a68a9ee0@mentor.com> Date: Mon, 17 Aug 2020 19:24:01 +0100 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:68.0) Gecko/20100101 Thunderbird/68.10.0 MIME-Version: 1.0 In-Reply-To: <20200817115744.GA3985908@kroah.com> Content-Type: text/plain; charset="utf-8" Content-Language: en-GB Content-Transfer-Encoding: 7bit X-Originating-IP: [137.202.0.90] X-ClientProxiedBy: svr-ies-mbx-01.mgc.mentorg.com (139.181.222.1) To SVR-IES-MBX-03.mgc.mentorg.com (139.181.222.3) X-Rspamd-Queue-Id: 2138118086CAB X-Spamd-Result: default: False [0.00 / 100.00] X-Rspamd-Server: rspam05 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 17/08/2020 12:57, Greg KH wrote: > On Mon, Aug 17, 2020 at 12:40:03PM +0100, Jim Baxter wrote: >> We have issues with the workqueue of the kernel overloading the CPU 0 >> when we we disconnect a USB stick. >> >> This results in other items on the shared workqueue being delayed by >> around 6.5 seconds with a default kernel configuration and 2.3 seconds >> on a config tailored for our RCar embedded platform. >> > > Is this data really flushed out to the device? > I am unsure if the delay is due to a single system or a combination of memory, usb or filesystem operations, the delay also occurs if the device is mounted as ro and using the sync option. Using umount stops the issue occurring but is unfortunately not guaranteed in our particular system. >> - Disconnect the USB stick: >> [ 1551.796792] usb 2-1: USB disconnect, device number 2 >> [ 1558.625517] DELAY: 6782 >> >> >> The Delay output 6782 is in milliseconds. > > What USB workqueue is taking so long?> > The one trying to deal with the filesystem flushing out the data that it > can't do now that the device is removed? :) > >From my analysis it is the hub_event workqueue shown to be using most of the CPU, the kworker/0:1+usb thread uses around 98% of the CPU. I have traced the workqueue:workqueue_queue_work function while unplugging the USB but not found a particular workqueue function being called a lot. Using perf Iidentified the hub_events workqueue was spending a lot of time in invalidate_partition(), I have included a cut down the captured data from perf in [2] which shows the additional functions where the kworker spends most of its time. I realise that not unmounting the USB stick is not ideal, though I wonder what additional work is done when unplugging the USB stick compared to unmounting it. I guess it may be waiting for a time-out during the operation without the unmount. Thanks, Jim Baxter > thanks, > > greg k-h > [2] perf trace: 95.22% 0.00% kworker/0:2-eve [kernel.kallsyms] | ---ret_from_fork kthread worker_thread | --95.15%--process_one_work | --94.99%--hub_event | --94.99%--usb_disconnect | --94.90%--invalidate_partition __invalidate_device | |--64.55%--invalidate_bdev | | | --64.13%--invalidate_mapping_pages | | | |--24.09%--invalidate_inode_page | | | | | --23.44%--remove_mapping | | | | | --23.20%--__remove_mapping | | | | | --21.90%--arch_local_irq_restore | | | |--22.44%--arch_local_irq_enable | --30.35%--shrink_dcache_sb | --30.17%--truncate_inode_pages_range