Received: by 2002:a6b:fb09:0:0:0:0:0 with SMTP id h9csp695191iog; Fri, 17 Jun 2022 11:26:08 -0700 (PDT) X-Google-Smtp-Source: AGRyM1v/ck8xSh4aerrDp29GH4z7Vga/3M/Zc4bFXjb5fma5RHIiQi+YYEIptbfGulxmZRdMM2Wa X-Received: by 2002:a17:906:f293:b0:718:82e3:226b with SMTP id gu19-20020a170906f29300b0071882e3226bmr10608350ejb.676.1655490368224; Fri, 17 Jun 2022 11:26:08 -0700 (PDT) ARC-Seal: i=1; a=rsa-sha256; t=1655490368; cv=none; d=google.com; s=arc-20160816; b=jlR4M2y/AxU0i4NClkJGGtOPX3R9YoVPchRjnbG13pEwyLkMLkYpZZlGJiNE0SgKSs EQsxaZOqdvo13OyitlK4n/cR6+tOftr1bjx/+TOm/FFiT9JsQZleptTEWXBxYeS5sY1Z C/wowFlWMwjszm1s+3c6gD/VYXDsz+HWQ6BbWq3geVxI42Od2pnieAK1Xv3400J5SFNX jq+4X9m3jNcVZHLMtIH1nPNvVQu1KuddmggabI8LxXBhDo7Fk3ZLlLgdFQdSiMEtD3QH LVI8RAyWJfns6EM7hdJ4AtRNUi9A/AzcU2cwNKZba7Y64qGycwvmK+cNOWlDkNWeFh7M g/Aw== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=list-id:precedence:cc:to:subject:message-id:date:from:in-reply-to :references:mime-version:dkim-signature; bh=MRsx6tWtUrc/LMBt7Ro9eEmVGTkFZYjS5XSEwg6Xnss=; b=QfMa8vjt3VdLMDvu9pD1smseCtaptZBPRD/2MJGLs1E8QgmI0HDRjil3KB6xa+Cof+ 1GpL+JAU2aHtQXo77dCUGAiVaaAV7KU30DjBGa2NhZsIwSf1nmIwdoQxlfl9vC3k4jzp Dp79N1yGzXLWWDg6XlFbBHuy1NZk5C+HXsTYq7Ixc2N5I1oidMAolwsv/yW6jKJ3eHsY /VgUJeTQsctZrehGOORmN2O53CBpekv4C/NA5d41WwzoXEs8ZbrN5NZ7OU7gzb41cosk fguZtU8WzKEmESZHQhmhDL813zWsRh6DQEiD9/UDvfujlQfTJgiExNMKMs62LoW4bo1P 5h9Q== ARC-Authentication-Results: i=1; mx.google.com; dkim=pass header.i=@google.com header.s=20210112 header.b=NTI+iENT; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=REJECT sp=REJECT dis=NONE) header.from=google.com Return-Path: Received: from out1.vger.email (out1.vger.email. [2620:137:e000::1:20]) by mx.google.com with ESMTP id y12-20020a056402440c00b0043555742fb6si5527699eda.224.2022.06.17.11.25.39; Fri, 17 Jun 2022 11:26:08 -0700 (PDT) Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20; Authentication-Results: mx.google.com; dkim=pass header.i=@google.com header.s=20210112 header.b=NTI+iENT; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=REJECT sp=REJECT dis=NONE) header.from=google.com Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1383345AbiFQSFW (ORCPT + 99 others); Fri, 17 Jun 2022 14:05:22 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:41062 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S239096AbiFQSFT (ORCPT ); Fri, 17 Jun 2022 14:05:19 -0400 Received: from mail-yw1-x1131.google.com (mail-yw1-x1131.google.com [IPv6:2607:f8b0:4864:20::1131]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 166281EED9 for ; Fri, 17 Jun 2022 11:05:18 -0700 (PDT) Received: by mail-yw1-x1131.google.com with SMTP id 00721157ae682-3176d94c236so49717367b3.3 for ; Fri, 17 Jun 2022 11:05:18 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=20210112; h=mime-version:references:in-reply-to:from:date:message-id:subject:to :cc; bh=MRsx6tWtUrc/LMBt7Ro9eEmVGTkFZYjS5XSEwg6Xnss=; b=NTI+iENTQ+9qMzOmscnJ3KfytjLOIBhhaBWsnw/nCqXq4E8jZ2ks0EFakxHa39xXXg U1ikIAeMJEROxnuiuqgknA3OV03OK1vjvLQxEzZQcUcrydhF9wAqqjaTmQQLYXs0F9H/ RntnDYerf5rHm47iQSF4QaDVuyGG33CtoCkEktY1wB9drJ28SMTP59RfUMniKjvTDMk9 c6xcPktzOoRWKP0vDNVoaj5L6vcz/Qs1i+rtgyF1vEIb8sWyynwCzxPuKn+tPBhjiN3P RCW88MI8P5qRu5YlSimU/XVb05wpgk46Mej0petSxgV/Bj9MxlEDliXMUtY/QNUV93gt sG/g== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:mime-version:references:in-reply-to:from:date :message-id:subject:to:cc; bh=MRsx6tWtUrc/LMBt7Ro9eEmVGTkFZYjS5XSEwg6Xnss=; b=GMj+aR9qw43rX7WsBTBH/ZHBvgWUEG60m7UyjcYXfB+yu1TZaRFDpv9TyErgH+2STW KHa5gF3IQ+kCJeyFrtQ84rc0mQyivQI00zK2lwxFpRjiIW0WB8yyuSCKmfOJDE1CYVPs u6vEHLVOc9MPh1Ff0WJyIO1WajXpCZY/bUBwnECd00OQu2lLHRVbTFgkKuHPQ+wh6LD/ W14QLkPArPOr7jTOUNmeu+WP+Txyb+zRG1il82xonO8dS8Pt8Yit45cJE/RIwMy0U/+c Tdf/xaY5LTLiA1pN9kXCGY1EhSBM1F4HNYpHQshr6BTnrh5VhaxH0SEz9Dl8a+NYttJ3 o0nQ== X-Gm-Message-State: AJIora/Wv+N0iYXrsGAxUtaVFh9uRBCMQ/WTXrF5vfro09uKZBg5GO4/ SOXrQbVQHzhiQZc1H+P/YWJ7dD0kwuWt0VS2UpI03g== X-Received: by 2002:a0d:d241:0:b0:317:8fee:4290 with SMTP id u62-20020a0dd241000000b003178fee4290mr1997890ywd.518.1655489116967; Fri, 17 Jun 2022 11:05:16 -0700 (PDT) MIME-Version: 1.0 References: In-Reply-To: From: Saravana Kannan Date: Fri, 17 Jun 2022 11:04:41 -0700 Message-ID: Subject: Re: Default async probing for DT based systems To: Marek Szyprowski Cc: LKML , linux-arm-kernel , Geert Uytterhoeven , Kevin Hilman , Greg Kroah-Hartman , Marc Zyngier , Will Deacon , Rob Herring , "Rafael J. Wysocki" , Ulf Hansson , Linus Walleij , Sebastian Andrzej Siewior , Android Kernel Team , Linux PM Content-Type: text/plain; charset="UTF-8" X-Spam-Status: No, score=-17.6 required=5.0 tests=BAYES_00,DKIMWL_WL_MED, DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF, ENV_AND_HDR_SPF_MATCH,RCVD_IN_DNSWL_NONE,SPF_HELO_NONE,SPF_PASS, T_SCC_BODY_TEXT_LINE,USER_IN_DEF_DKIM_WL,USER_IN_DEF_SPF_WL autolearn=ham autolearn_force=no version=3.4.6 X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on lindbergh.monkeyblade.net Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Fri, Jun 17, 2022 at 2:04 AM Marek Szyprowski wrote: > > Hi Saravana, > > On 16.06.2022 05:24, Saravana Kannan wrote: > > Hi, > > > > TL;DR: I want to improve boot times by enabling async probing by > > default for DT based systems. Can you give it a shot please? > > Yes, I've gave it a try on my test systems. It looks that there are a > few issues. The first one, the most obvious to notice, is related to > __request_module() calls from various drivers and frameworks. Here are > some examples: > > ------------[ cut here ]------------ > WARNING: CPU: 3 PID: 73 at kernel/kmod.c:136 __request_module+0x230/0x600 > Modules linked in: > CPU: 3 PID: 73 Comm: kworker/u12:5 Not tainted 5.19.0-rc2-next-20220615+ > #5203 > Hardware name: ARM Juno development board (r1) (DT) > Workqueue: events_unbound async_run_entry_fn > pstate: 00000005 (nzcv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--) > UDC core: g_ether: couldn't find an available UDC > pc : __request_module+0x230/0x600 > lr : __request_module+0x228/0x600 Ah, I think I know what these might be. Going by memory, __request_module() from asyc thread context has some issues for module loading. So I think a check was added like this. And I think the check is triggering when it shouldn't (this isn't module context here). > ... > Call trace: > __request_module+0x230/0x600 > phy_request_driver_module+0x118/0x164 > phy_device_create+0x210/0x23c > get_phy_device+0x8c/0x160 > mdiobus_scan+0x40/0x1cc > __mdiobus_register+0x184/0x36c > smsc911x_drv_probe+0x648/0xa84 > platform_probe+0x68/0xe0 > really_probe+0xbc/0x2e0 > __driver_probe_device+0x78/0xe0 > driver_probe_device+0xa8/0x140 > __driver_attach_async_helper+0x50/0xbc > async_run_entry_fn+0x34/0xd0 > process_one_work+0x288/0x6bc > worker_thread+0x74/0x450 > kthread+0x118/0x11c > ret_from_fork+0x10/0x20 > irq event stamp: 2032 > hardirqs last enabled at (2031): [] > _raw_spin_unlock_irqrestore+0x98/0x9c > hardirqs last disabled at (2032): [] el1_dbg+0x24/0x90 > softirqs last enabled at (2018): [] _stext+0x470/0x5e8 > softirqs last disabled at (2007): [] > __irq_exit_rcu+0x180/0x1ac > ---[ end trace 0000000000000000 ]--- > > ------------[ cut here ]------------ > WARNING: CPU: 0 PID: 54 at kernel/kmod.c:136 __request_module+0x230/0x600 > Modules linked in: rng_core(+) rtc_meson_vrtc(+) mdio_mux_meson_g12a(+) > meson_ir pcs_xpcs meson_canvas(+) meson_dw_hdmi dw_hdmi > snd_soc_meson_axg_tdm_interface di > xg_tdm_formatter nvmem_meson_efuse > CPU: 0 PID: 54 Comm: kworker/u8:3 Not tainted 5.19.0-rc2-next-20220615+ > #5203 > Hardware name: Hardkernel ODROID-C4 (DT) > Workqueue: events_unbound async_run_entry_fn > pstate: 00400009 (nzcv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--) > pc : __request_module+0x230/0x600 > lr : __request_module+0x228/0x600 > ... > Call trace: > __request_module+0x230/0x600 > rc_map_get+0xa8/0x134 > rc_register_device+0x10c/0x600 > devm_rc_register_device+0x4c/0x170 > meson_ir_probe+0x160/0x2bc [meson_ir] > platform_probe+0x68/0xe0 > really_probe+0xbc/0x2e0 > __driver_probe_device+0x78/0xe0 > driver_probe_device+0x3c/0x140 > __driver_attach_async_helper+0x50/0xbc > async_run_entry_fn+0x34/0xd0 > process_one_work+0x288/0x6bc > worker_thread+0x74/0x450 > kthread+0x118/0x11c > ret_from_fork+0x10/0x20 > irq event stamp: 62052 > hardirqs last enabled at (62051): [] > ___slab_alloc+0x734/0x82c > hardirqs last disabled at (62052): [] el1_dbg+0x24/0x90 > softirqs last enabled at (61920): [] _stext+0x470/0x5e8 > softirqs last disabled at (61859): [] > __irq_exit_rcu+0x180/0x1ac > ---[ end trace 0000000000000000 ]--- > > ------------[ cut here ]------------ > WARNING: CPU: 0 PID: 46 at kernel/kmod.c:136 __request_module+0x230/0x600 > Modules linked in: > CPU: 0 PID: 46 Comm: kworker/u4:4 Not tainted 5.19.0-rc2-next-20220615+ > #5203 > Hardware name: linux,dummy-virt (DT) > Workqueue: events_unbound async_run_entry_fn > pstate: 00000005 (nzcv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--) > pc : __request_module+0x230/0x600 > lr : __request_module+0x228/0x600 > ... > Call trace: > __request_module+0x230/0x600 > parse_mtd_partitions+0x2b4/0x490 > mtd_device_parse_register+0x90/0x2bc > physmap_flash_probe+0x4c8/0x7b0 > platform_probe+0x68/0xe0 > really_probe+0xbc/0x2e0 > __driver_probe_device+0x78/0xe0 > driver_probe_device+0xa8/0x140 > __driver_attach_async_helper+0x50/0xbc > async_run_entry_fn+0x34/0xd0 > process_one_work+0x288/0x6bc > worker_thread+0x74/0x450 > kthread+0x118/0x11c > ret_from_fork+0x10/0x20 > irq event stamp: 674 > hardirqs last enabled at (673): [] > vprintk_store+0x440/0x4a0 > hardirqs last disabled at (674): [] el1_dbg+0x24/0x90 > softirqs last enabled at (618): [] _stext+0x470/0x5e8 > softirqs last disabled at (613): [] > __irq_exit_rcu+0x180/0x1ac > ---[ end trace 0000000000000000 ]--- > > ------------[ cut here ]------------ > WARNING: CPU: 0 PID: 63 at kernel/kmod.c:136 __request_module+0x23c/0x42c > Modules linked in: exynos_bus soundcore s5p_mfc lima brcmutil > drm_shmem_helper exynos_adc gpu_sched sha256_generic libsha256 > sha256_arm cfg80211 phy_exynos_usb2 s > dma_contig videobuf2_memops videobuf2_v4l2 videobuf2_common videodev > exynosdrm analogix_dp mc exynos_ppmu rtc_s3c i2c_gpio > CPU: 0 PID: 63 Comm: kworker/u4:5 Not tainted > 5.19.0-rc2-next-20220615-00040-g868471ca3680-dirty #5205 > Hardware name: Samsung Exynos (Flattened Device Tree) > Workqueue: events_unbound async_run_entry_fn > unwind_backtrace from show_stack+0x10/0x14 > show_stack from dump_stack_lvl+0x40/0x4c > dump_stack_lvl from __warn+0xcc/0x144 > __warn from warn_slowpath_fmt+0x5c/0xb4 > warn_slowpath_fmt from __request_module+0x23c/0x42c > __request_module from try_then_request_governor+0x60/0xb0 > try_then_request_governor from devfreq_add_device+0x498/0x5c8 > devfreq_add_device from devm_devfreq_add_device+0x58/0x94 > devm_devfreq_add_device from exynos_bus_probe+0x1b4/0x6bc [exynos_bus] > exynos_bus_probe [exynos_bus] from platform_probe+0x5c/0xb8 > platform_probe from really_probe+0xc8/0x2f0 > really_probe from __driver_probe_device+0x84/0xe4 > __driver_probe_device from driver_probe_device+0x30/0x104 > driver_probe_device from __driver_attach_async_helper+0x48/0x98 > __driver_attach_async_helper from async_run_entry_fn+0x24/0xb0 > async_run_entry_fn from process_one_work+0x1ec/0x4d0 > process_one_work from worker_thread+0x58/0x54c > worker_thread from kthread+0xd0/0xec > kthread from ret_from_fork+0x14/0x2c > Exception stack(0xe0349fb0 to 0xe0349ff8) > ... > ---[ end trace 0000000000000000 ]--- > ------------[ cut here ]------------ > WARNING: CPU: 0 PID: 63 at kernel/kmod.c:136 __request_module+0x23c/0x42c > Modules linked in: exynos_bus soundcore s5p_mfc lima brcmutil > drm_shmem_helper exynos_adc gpu_sched sha256_generic libsha256 > sha256_arm cfg80211 phy_exynos_usb2 s > dma_contig videobuf2_memops videobuf2_v4l2 videobuf2_common videodev > exynosdrm analogix_dp mc exynos_ppmu rtc_s3c i2c_gpio > CPU: 0 PID: 63 Comm: kworker/u4:5 Not tainted > 5.19.0-rc2-next-20220615-00040-g868471ca3680-dirty #5205 > Hardware name: Samsung Exynos (Flattened Device Tree) > Workqueue: events_unbound async_run_entry_fn > unwind_backtrace from show_stack+0x10/0x14 > show_stack from dump_stack_lvl+0x40/0x4c > dump_stack_lvl from __warn+0xcc/0x144 > __warn from warn_slowpath_fmt+0x5c/0xb4 > warn_slowpath_fmt from __request_module+0x23c/0x42c > __request_module from try_then_request_governor+0x60/0xb0 > try_then_request_governor from devfreq_add_device+0x498/0x5c8 > devfreq_add_device from devm_devfreq_add_device+0x58/0x94 > devm_devfreq_add_device from exynos_bus_probe+0x1b4/0x6bc [exynos_bus] > exynos_bus_probe [exynos_bus] from platform_probe+0x5c/0xb8 > platform_probe from really_probe+0xc8/0x2f0 > really_probe from __driver_probe_device+0x84/0xe4 > __driver_probe_device from driver_probe_device+0x30/0x104 > driver_probe_device from __driver_attach_async_helper+0x48/0x98 > __driver_attach_async_helper from async_run_entry_fn+0x24/0xb0 > async_run_entry_fn from process_one_work+0x1ec/0x4d0 > process_one_work from worker_thread+0x58/0x54c > worker_thread from kthread+0xd0/0xec > kthread from ret_from_fork+0x14/0x2c > Exception stack(0xe0349fb0 to 0xe0349ff8) > ... > ---[ end trace 0000000000000000 ]--- > > ------------[ cut here ]------------ > WARNING: CPU: 0 PID: 23 at kernel/kmod.c:136 __request_module+0x23c/0x42c > Modules linked in: g_ether usb_f_rndis u_ether libcomposite brcmfmac > brcmutil sha256_generic libsha256 snd_soc_hdmi_codec snd_soc_core > sha256_arm ac97_bus snd_pcm > _timer snd soundcore panel_samsung_ld9040 hci_uart btbcm bluetooth > s5p_csis s5p_fimc exynos4_is_common v4l2_fwnode ecdh_generic ecc > v4l2_async spi_gpio phy_exynos > x8998 pwm_samsung max8952 drm_shmem_helper libaes s5p_mfc gpu_sched > s5p_jpeg v4l2_mem2mem videobuf2_dma_contig videobuf2_memops > videobuf2_v4l2 phy_exynos_usb2 vid > m ohci_exynos ehci_exynos analogix_dp mc s5p_sss exynos_rng rtc_s3c > s3c2410_wdt i2c_gpio > CPU: 0 PID: 23 Comm: kworker/u4:7 Not tainted > 5.19.0-rc2-next-20220615-00040-g868471ca3680-dirty #5205 > Hardware name: Samsung Exynos (Flattened Device Tree) > Workqueue: events_unbound async_run_entry_fn > unwind_backtrace from show_stack+0x10/0x14 > show_stack from dump_stack_lvl+0x40/0x4c > dump_stack_lvl from __warn+0xcc/0x144 > __warn from warn_slowpath_fmt+0x5c/0xb4 > warn_slowpath_fmt from __request_module+0x23c/0x42c > __request_module from usb_get_function_instance+0x3c/0x58 [libcomposite] > usb_get_function_instance [libcomposite] from eth_bind+0x3c/0x334 > [g_ether] > eth_bind [g_ether] from composite_bind+0x78/0x18c [libcomposite] > composite_bind [libcomposite] from gadget_bind_driver+0x8c/0x1d0 > gadget_bind_driver from really_probe+0xc8/0x2f0 > really_probe from __driver_probe_device+0x84/0xe4 > __driver_probe_device from driver_probe_device+0x30/0x104 > driver_probe_device from __driver_attach_async_helper+0x48/0x98 > __driver_attach_async_helper from async_run_entry_fn+0x24/0xb0 > async_run_entry_fn from process_one_work+0x1ec/0x4d0 > process_one_work from worker_thread+0x58/0x54c > worker_thread from kthread+0xd0/0xec > kthread from ret_from_fork+0x14/0x2c > Exception stack(0xe08ddfb0 to 0xe08ddff8) > ... > ---[ end trace 0000000000000000 ]--- > > > Some Exynos-based boards also freeze quite early, after the 'EXYNOS5420 > PMU initialized' message. I will investigate this later once I find some > spare time. Thanks! -Saravana > > > ... > > Best regards > -- > Marek Szyprowski, PhD > Samsung R&D Institute Poland > > -- > To unsubscribe from this group and stop receiving emails from it, send an email to kernel-team+unsubscribe@android.com. >