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=-3.8 required=3.0 tests=BAYES_00, 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 21D09C433DF for ; Wed, 14 Oct 2020 16:40:16 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by mail.kernel.org (Postfix) with ESMTP id B37A4214D8 for ; Wed, 14 Oct 2020 16:40:15 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1727735AbgJNQkP (ORCPT ); Wed, 14 Oct 2020 12:40:15 -0400 Received: from mail-ot1-f65.google.com ([209.85.210.65]:41428 "EHLO mail-ot1-f65.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1726463AbgJNQkP (ORCPT ); Wed, 14 Oct 2020 12:40:15 -0400 Received: by mail-ot1-f65.google.com with SMTP id n15so212659otl.8; Wed, 14 Oct 2020 09:40:12 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:references:in-reply-to:from:date :message-id:subject:to:cc; bh=awjbHZmaw2mEvGp1mgXDc8wUbmV5fwPzQ3ps5KMPm2k=; b=dIQYUIwoQZuAy5/qCFPM9JK+W2hP2Uxv/jC85VeJM39dk4Bx8Y2hiPwSPQtVYqxfzc n+TDMIXuMTiWq0NF7o9FgpLf5zJMtUz4Dn7zOTY/Cmmrwxjxc4u8ckpIICmNNSyuGjEr wOvWGMYu9MHks7JzrbNP5+VFi73sGSRepxtPG5K1yXeJMS7V0d9gpcgCz8/swibN66z4 JBaUOWZhCmIhADaX1/wN/zC7xZnhfEex8kwAfHd0IOAC+vC8ZGDf2OqJQGmIxrUndGC0 d6+vn3+iD665jWd+kqi6F7mCAGOlbjIqs84qGjSmnTAt9EzPgmbU2EriC7FhqDGiEw0u b7Og== X-Gm-Message-State: AOAM5321G6h2lHuTBXVgf2NSRXp9oZ2MSaWHGmaXEF/8GJX93lHsHSV3 oAoCqR7L4LTvQWBpYo9cWoOwmZbjUc1SpwoiJw+eZx3hovQ= X-Google-Smtp-Source: ABdhPJyYK2BVffULinxkJTUaiKwHo3meDTY743HeDhNG3lORiwXgdZJDNH08E2bm6s/8cQMeFhZcrppTESI6pU154/Y= X-Received: by 2002:a05:6830:210a:: with SMTP id i10mr4108019otc.145.1602693612028; Wed, 14 Oct 2020 09:40:12 -0700 (PDT) MIME-Version: 1.0 References: <24ff92dd1b0ee1b802b45698520f2937418f8094.1598260050.git.viresh.kumar@linaro.org> <20201013095613.mbgmjwzojg5wxmau@vireshk-i7> In-Reply-To: <20201013095613.mbgmjwzojg5wxmau@vireshk-i7> From: Geert Uytterhoeven Date: Wed, 14 Oct 2020 18:40:00 +0200 Message-ID: Subject: Re: [PATCH V2 2/2] cpufreq: dt: Refactor initialization to handle probe deferral properly To: Viresh Kumar Cc: Stephan Gerhold , Ulf Hansson , "Rafael J. Wysocki" , Liam Girdwood , Mark Brown , Linux PM list , Vincent Guittot , Stephen Boyd , Nishanth Menon , nks@flawful.org, Georgi Djakov , Linux Kernel Mailing List , Wolfram Sang , Linux I2C , Linux-Renesas Content-Type: text/plain; charset="UTF-8" Precedence: bulk List-ID: X-Mailing-List: linux-i2c@vger.kernel.org Hi Viresh, On Tue, Oct 13, 2020 at 11:56 AM Viresh Kumar wrote: > On 13-10-20, 11:47, Geert Uytterhoeven wrote: > > Thanks for your patch, which is now commit dc279ac6e5b4e06e ("cpufreq: > > dt: Refactor initialization to handle probe deferral properly") in > > pm/linux-next, and to which I bisected a regression. > > Reverting this commit fixes the issue. > > Strange. I had a look again and I failed to understand why it would > happen this way. > > > On r8a7791/koelsch, during resume from s2ram: > > > > PM: suspend entry (deep) > > Filesystems sync: 0.000 seconds > > Freezing user space processes ... (elapsed 0.003 seconds) done. > > OOM killer disabled. > > Freezing remaining freezable tasks ... (elapsed 0.009 seconds) done. > > Disabling non-boot CPUs ... > > Enabling non-boot CPUs ... > > +i2c-sh_mobile e60b0000.i2c: Transfer request timed out > > +i2c-sh_mobile e60b0000.i2c: Transfer request timed out > > +i2c-sh_mobile e60b0000.i2c: Transfer request timed out > > +i2c-sh_mobile e60b0000.i2c: Transfer request timed out > > +i2c-sh_mobile e60b0000.i2c: Transfer request timed out > > +i2c-sh_mobile e60b0000.i2c: Transfer request timed out > > +i2c-sh_mobile e60b0000.i2c: Transfer request timed out > > +i2c-sh_mobile e60b0000.i2c: Transfer request timed out > > +i2c-sh_mobile e60b0000.i2c: Transfer request timed out > > +i2c-sh_mobile e60b0000.i2c: Transfer request timed out > > +i2c-sh_mobile e60b0000.i2c: Transfer request timed out > > +i2c-sh_mobile e60b0000.i2c: Transfer request timed out > > +cpu cpu0: OPP table can't be empty > > CPU1 is up > > rcar-pcie fe000000.pcie: PCIe x1: link up > > > > The cpufreq code tries to talk to the PMIC, while the I2C controller > > that hosts the PMIC is suspended, and thus any communication attempt > > times out. __i2c_check_suspended() fails to notice that, as the > > i2c_shmobile_i2c driver doesn't have a suspend callback calling > > i2c_mark_adapter_suspended() yet. After fixing that (will send a patch > > soon), the I2C core rightfully complains with: > > > > WARNING: CPU: 1 PID: 13 at drivers/i2c/i2c-core.h:54 > > __i2c_transfer+0x4a4/0x4e4 > > i2c i2c-6: Transfer while suspended > > CPU: 1 PID: 13 Comm: cpuhp/1 Not tainted > > 5.9.0-shmobile-09581-g05a3e5886c7615b1-dirty #718 > > Hardware name: Generic R-Car Gen2 (Flattened Device Tree) > > [] (unwind_backtrace) from [] (show_stack+0x10/0x14) > > [] (show_stack) from [] (dump_stack+0x8c/0xac) > > [] (dump_stack) from [] (__warn+0xd0/0xe8) > > [] (__warn) from [] (warn_slowpath_fmt+0x70/0x9c) > > [] (warn_slowpath_fmt) from [] > > (__i2c_transfer+0x4a4/0x4e4) > > [] (__i2c_transfer) from [] (i2c_transfer+0xb0/0xf8) > > [] (i2c_transfer) from [] (regmap_i2c_read+0x54/0x88) > > [] (regmap_i2c_read) from [] > > (_regmap_raw_read+0x118/0x1f0) > > [] (_regmap_raw_read) from [] > > (_regmap_bus_read+0x44/0x68) > > [] (_regmap_bus_read) from [] (_regmap_read+0x84/0x110) > > [] (_regmap_read) from [] (regmap_read+0x40/0x58) > > [] (regmap_read) from [] > > (regulator_get_voltage_sel_regmap+0x28/0x74) > > [] (regulator_get_voltage_sel_regmap) from [] > > (regulator_get_voltage_rdev+0xa4/0x14c) > > [] (regulator_get_voltage_rdev) from [] > > (regulator_get_voltage+0x2c/0x60) > > [] (regulator_get_voltage) from [] > > (regulator_is_supported_voltage+0x30/0xd8) > > [] (regulator_is_supported_voltage) from [] > > (_opp_add+0x164/0x1b8) > > [] (_opp_add) from [] (_opp_add_v1+0x80/0xb8) > > [] (_opp_add_v1) from [] > > (dev_pm_opp_of_add_table+0x130/0x168) > > [] (dev_pm_opp_of_add_table) from [] > > (dev_pm_opp_of_cpumask_add_table+0x60/0xac) > > [] (dev_pm_opp_of_cpumask_add_table) from [] > > (cpufreq_init+0x94/0x1c4) > > [] (cpufreq_init) from [] (cpufreq_online+0x148/0x7ac) > > [] (cpufreq_online) from [] > > (cpuhp_cpufreq_online+0x8/0x10) > > [] (cpuhp_cpufreq_online) from [] > > (cpuhp_invoke_callback+0xf8/0x2e4) > > [] (cpuhp_invoke_callback) from [] > > (cpuhp_thread_fun+0xac/0x244) > > [] (cpuhp_thread_fun) from [] > > (smpboot_thread_fn+0x19c/0x1a8) > > [] (smpboot_thread_fn) from [] (kthread+0x104/0x110) > > [] (kthread) from [] (ret_from_fork+0x14/0x2c) > > So there is a dependency chain here. cpufreq->regulator->i2c, > specially with the patch you pointed out, we handle defer-probing in a > better way and so I would expect i2c driver to get in first and > cpufreq should get registered later only. And I would have expected > the same during suspend/resume. > > Can you see why this happens ? On this platform (r8a7791-koelsch.dts), there is no opp table in DT. Before: boot: cpufreq-dt cpufreq-dt: dt_cpufreq_probe:362 cpu cpu0: resources_available:95 cpu cpu0: resources_available:102: clk_get() returned z cpu cpu0: resources_available:120: dev_pm_opp_of_find_icc_paths() returned 0 cpu cpu0: resources_available:125: find_supply_name() returned cpu0 cpu cpu0: resources_available:132: regulator_get_optional() returned -EPROBE_DEFER cpu cpu0: cpu0 regulator not ready, retry cpufreq-dt cpufreq-dt: dt_cpufreq_probe:371: resources_available() returned -517 ... cpufreq-dt cpufreq-dt: dt_cpufreq_probe:362 cpu cpu0: resources_available:95 cpu cpu0: resources_available:102: clk_get() returned z cpu cpu0: resources_available:120: dev_pm_opp_of_find_icc_paths() returned 0 cpu cpu0: resources_available:125: find_supply_name() returned cpu0 cpu cpu0: resources_available:132: regulator_get_optional() returned (ptrval) cpufreq-dt cpufreq-dt: dt_cpufreq_probe:371: resources_available() returned 0 cpufreq-dt cpufreq-dt: dt_cpufreq_probe:375 cpufreq_dt: cpufreq_init:162 cpu cpu0: cpufreq_init:170: clk_get() returned z cpu cpu0: cpufreq_init:179: dev_pm_opp_of_get_sharing_cpus() returned -2 cpu cpu0: cpufreq_init:198: find_supply_name() returned cpu0 cpu cpu0: cpufreq_init:201: dev_pm_opp_set_regulators() returned (ptrval) cpu cpu0: cpufreq_init:230: dev_pm_opp_of_cpumask_add_table() returned 0 cpu cpu0: cpufreq_init:239: dev_pm_opp_get_opp_count() returned 0 cpu cpu0: OPP table is not ready, deferring probe cpufreq_dt: cpufreq_init:162 cpu cpu1: cpufreq_init:170: clk_get() returned z cpu cpu1: cpufreq_init:179: dev_pm_opp_of_get_sharing_cpus() returned -2 cpu cpu1: no regulator for cpu1 cpu cpu1: cpufreq_init:198: find_supply_name() returned (null) cpu cpu1: cpufreq_init:230: dev_pm_opp_of_cpumask_add_table() returned 0 cpu cpu1: cpufreq_init:239: dev_pm_opp_get_opp_count() returned 0 cpu cpu1: OPP table is not ready, deferring probe s2ram: cpufreq_dt: cpufreq_init:162 cpu cpu1: cpufreq_init:170: clk_get() returned z cpu cpu1: cpufreq_init:179: dev_pm_opp_of_get_sharing_cpus() returned -2 cpu cpu1: no regulator for cpu1 cpu cpu1: cpufreq_init:198: find_supply_name() returned (null) cpu cpu1: cpufreq_init:230: dev_pm_opp_of_cpumask_add_table() returned 0 cpu cpu1: cpufreq_init:239: dev_pm_opp_get_opp_count() returned 0 cpu cpu1: OPP table is not ready, deferring probe CPU1 is up After: boot: cpufreq-dt cpufreq-dt: dt_cpufreq_probe:356 cpufreq_dt: dt_cpufreq_early_init:251 cpu cpu0: dt_cpufreq_early_init:256 cpu cpu0: dt_cpufreq_early_init:271: dev_pm_opp_get_opp_table() returned (ptrval) cpu cpu0: dt_cpufreq_early_init:284: find_supply_name() returned cpu0 cpu cpu0: dt_cpufreq_early_init:288: dev_pm_opp_set_regulators() returned -EPROBE_DEFER cpufreq-dt cpufreq-dt: dt_cpufreq_probe:360: dt_cpufreq_early_init() returned -517 ... cpufreq-dt cpufreq-dt: dt_cpufreq_probe:356 cpufreq_dt: dt_cpufreq_early_init:251 cpu cpu0: dt_cpufreq_early_init:256 cpu cpu0: dt_cpufreq_early_init:271: dev_pm_opp_get_opp_table() returned (ptrval) cpu cpu0: dt_cpufreq_early_init:284: find_supply_name() returned cpu0 cpu cpu0: dt_cpufreq_early_init:288: dev_pm_opp_set_regulators() returned (ptrval) cpu cpu0: dt_cpufreq_early_init:301: dev_pm_opp_of_get_sharing_cpus() returned -2 cpufreq-dt cpufreq-dt: dt_cpufreq_probe:360: dt_cpufreq_early_init() returned 0 cpufreq_dt: dt_cpufreq_early_init:251 cpufreq-dt cpufreq-dt: dt_cpufreq_probe:360: dt_cpufreq_early_init() returned 0 cpufreq-dt cpufreq-dt: dt_cpufreq_probe:365 cpufreq_dt: cpufreq_init:114 cpu cpu0: cpufreq_init:124: clk_get() returned z cpu cpu0: cpufreq_init:142: dev_pm_opp_of_cpumask_add_table() returned 0 cpu cpu0: cpufreq_init:151: dev_pm_opp_get_opp_count() returned 0 cpu cpu0: OPP table can't be empty cpufreq_dt: cpufreq_init:114 cpu cpu0: cpufreq_init:124: clk_get() returned z cpu cpu0: cpufreq_init:142: dev_pm_opp_of_cpumask_add_table() returned 0 cpu cpu0: cpufreq_init:151: dev_pm_opp_get_opp_count() returned 0 s2ram: cpufreq_dt: cpufreq_init:114 cpu cpu0: cpufreq_init:124: clk_get() returned z WARNING: CPU: 1 PID: 14 at drivers/i2c/i2c-core.h:54 __i2c_transfer+0x2d8/0x310 i2c i2c-6: Transfer while suspended cpu cpu0: cpufreq_init:142: dev_pm_opp_of_cpumask_add_table() returned 0 cpu cpu0: cpufreq_init:151: dev_pm_opp_get_opp_count() returned 0 cpu cpu0: OPP table can't be empty CPU1 is up I hope this helps. Thanks! Gr{oetje,eeting}s, Geert -- Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org In personal conversations with technical people, I call myself a hacker. But when I'm talking to journalists I just say "programmer" or something like that. -- Linus Torvalds