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.2 required=3.0 tests=BAYES_00, HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI,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 3ADAAC433E1 for ; Mon, 17 Aug 2020 11:40:29 +0000 (UTC) Received: from kanga.kvack.org (kanga.kvack.org [205.233.56.17]) by mail.kernel.org (Postfix) with ESMTP id D22632067C for ; Mon, 17 Aug 2020 11:40:28 +0000 (UTC) DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org D22632067C 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 2FDE88D0002; Mon, 17 Aug 2020 07:40:28 -0400 (EDT) Received: by kanga.kvack.org (Postfix, from userid 40) id 286316B0006; Mon, 17 Aug 2020 07:40:28 -0400 (EDT) X-Delivered-To: int-list-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix, from userid 63042) id 1501B8D0002; Mon, 17 Aug 2020 07:40:28 -0400 (EDT) X-Delivered-To: linux-mm@kvack.org Received: from forelay.hostedemail.com (smtprelay0216.hostedemail.com [216.40.44.216]) by kanga.kvack.org (Postfix) with ESMTP id F0CCA6B0005 for ; Mon, 17 Aug 2020 07:40:27 -0400 (EDT) Received: from smtpin20.hostedemail.com (10.5.19.251.rfc1918.com [10.5.19.251]) by forelay02.hostedemail.com (Postfix) with ESMTP id 9E6A53647 for ; Mon, 17 Aug 2020 11:40:27 +0000 (UTC) X-FDA: 77159867694.20.scale01_21112fb27016 Received: from filter.hostedemail.com (10.5.16.251.rfc1918.com [10.5.16.251]) by smtpin20.hostedemail.com (Postfix) with ESMTP id 6F472180C07A3 for ; Mon, 17 Aug 2020 11:40:27 +0000 (UTC) X-HE-Tag: scale01_21112fb27016 X-Filterd-Recvd-Size: 4117 Received: from esa3.mentor.iphmx.com (esa3.mentor.iphmx.com [68.232.137.180]) by imf49.hostedemail.com (Postfix) with ESMTP for ; Mon, 17 Aug 2020 11:40:26 +0000 (UTC) IronPort-SDR: YG0TqEGM6oo7Un8bhNTHBXPzS3NlllP7USV2JfTljIFOfiRMJNQ+WBBu9WHavNjv4qvKM7ipym Z+ZNJECHf440rt+v9vu7+/Sw74BKITP9gyreSNwL6KHGOQP2G6gktpeZM2hGR5/L2b3cxqpOJX C61Ojxq91ss8Xzr6QvnWlNPu0OE4VGBv9695MxIMRgOAwLeMzhtwA+eLbAMraMuHLHHhK8sfng 8bztmb/Sbr1cJZU3Gpkg6EZP8LwO9FldqYyflENofH6SozvsEEvpfWVdUho4Nsr+weRHHECB7U c5E= X-IronPort-AV: E=Sophos;i="5.76,322,1592899200"; d="scan'208";a="51957663" Received: from orw-gwy-02-in.mentorg.com ([192.94.38.167]) by esa3.mentor.iphmx.com with ESMTP; 17 Aug 2020 03:40:24 -0800 IronPort-SDR: cwbtSVHmdpLaTlkjr/UF5ziHgd9DIztGwkD/FbAokHdQgOsK9A9gFr+lvvZdVpAQEQfXsTFzi+ FnQZ0jsZc7tqVsTwto2mOKyYUCBO8RtCdC/OITMdrn/CYd38sW+4/npq9YGcikhKk7lxzu5Re/ hn2uY/dwlXA/THkMNwTwmyzVdbfi4TDU8OKWXInys6X9wQaqhaJkru6HfC0Q9Z4xGWLZYHbi1v bUAwf7H6aspVAysWJIGS4pvwuoeg8PvreNz6/5nQnNwVFxQ3rlvHBlYnnC9q0UdeyiiDZyWIrJ 96s= To: , , CC: "Resch Carsten (CM/ESO6)" , "Rosca, Eugeniu (ADITG/ESB)" From: Jim Baxter Subject: PROBLEM: Long Workqueue delays. Message-ID: <71aafe68-7fe0-6b77-ea8e-83edd3f16c8d@mentor.com> Date: Mon, 17 Aug 2020 12:40:03 +0100 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:68.0) Gecko/20100101 Thunderbird/68.10.0 MIME-Version: 1.0 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-06.mgc.mentorg.com (139.181.222.6) To SVR-IES-MBX-03.mgc.mentorg.com (139.181.222.3) X-Rspamd-Queue-Id: 6F472180C07A3 X-Spamd-Result: default: False [0.00 / 100.00] X-Rspamd-Server: rspam02 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: 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. I am aware there will be delays on the shared workqueue, are the delays we are seeing considered normal? We first noticed this issue on custom hardware and we have recreated it on an RCar Starter Kit using a test module [1] to replicate the behaviour, the test module outputs any delays of greater then 9ms. To run the test we have a 4GB random file on a USB stick and perform the following test: - Load the Module: # taskset -c 0 modprobe latency-mon - Copy large amount of data from the stick: # dd if=/run/media/sda1/sample.txt of=/dev/zero [ 1437.517603] DELAY: 10 8388607+1 records in 8388607+1 records out - 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. Thank you for you help. Jim Baxter [1] Test Module: // SPDX-License-Identifier: GPL-2.0 /* * Simple WQ latency monitoring * * Copyright (C) 2020 Advanced Driver Information Technology. */ #include #include #include #define PERIOD_MS 100 static struct delayed_work wq; static u64 us_save; static void wq_cb(struct work_struct *work) { u64 us = ktime_to_us(ktime_get()); u64 us_diff = us - us_save; u64 us_print = 0; if (!us_save) goto skip_print; us_print = us_diff / 1000 - PERIOD_MS; if (us_print > 9) pr_crit("DELAY: %lld\n", us_print); skip_print: us_save = us; schedule_delayed_work(&wq, msecs_to_jiffies(PERIOD_MS)); } static int latency_mon_init(void) { us_save = 0; INIT_DELAYED_WORK(&wq, wq_cb); schedule_delayed_work(&wq, msecs_to_jiffies(PERIOD_MS)); return 0; } static void latency_mon_exit(void) { cancel_delayed_work_sync(&wq); pr_info("%s\n", __func__); } module_init(latency_mon_init); module_exit(latency_mon_exit); MODULE_AUTHOR("Eugeniu Rosca "); MODULE_LICENSE("GPL");