Hi Tony,
> Am 17.04.2020 um 17:07 schrieb Tony Lindgren <tony@xxxxxxxxxxx>:
>
> * H. Nikolaus Schaller <hns@xxxxxxxxxxxxx> [200417 14:53]:
>>
>>> Am 17.04.2020 um 16:43 schrieb Andreas Kemnade <andreas@xxxxxxxxxxxx>:
>>>
>>> On Fri, 17 Apr 2020 16:22:47 +0200
>>> "H. Nikolaus Schaller" <hns@xxxxxxxxxxxxx> wrote:
>>>
>>>>> Am 16.04.2020 um 20:46 schrieb Tony Lindgren <tony@xxxxxxxxxxx>:
>>>>> Care to check if changing pm_runtime_set_autosuspend_delay value
>>>>> to -1 in probe makes the issue go away? Or change it manually
>>>>> to -1 via sysfs.
>>>>>
>>>>> If that helps, likely we have a missing pm_runtime_get_sync()
>>>>> somewhere in the driver.
>>>>
>>>> Yes, it does! It suffices to set it to -1 for one readout.
>>>> Aything else I can test?
>
> You could sprinkle dev_info(dev, "%s\n", __func__) to the
> omap_hdq_runtime_suspend() and omap_hdq_runtime_resume()
> functions.
I have done it incl. adding dev_info to hdq_read_byte(). It
looks as if the read attempts already time out during boot,
but after omap_hdq_runtime_resume(). And omap_hdq_runtime_resume()
is done well after the last one. This looks ok.
echo -1 >autosuspend_delay_ms
Does omap_hdq_runtime_resume() once.
To me it looks as if reading hqd too quickly after omap_hdq_runtime_resume()
may be part of the problem, although it is 0.4 seconds between [ 18.355163]
and [ 18.745269]. So I am not sure about my interpretation.
A different attempt for interpretation may be that trying to read the
slave triggers omap_hdq_runtime_resume() just before doing the
first hdq_read_byte().
This may be different context from separating these steps into different
processes/threads (echo + cat).
I.e.
[ 18.355163] omap_hdq 480b2000.1w: omap_hdq_runtime_resume
[ 18.432403] omap_hdq 480b2000.1w: OMAP HDQ Hardware Rev 0.5. Driver in Interrupt mode
[ 18.745269] omap_hdq 480b2000.1w: hdq_read_byte
somehow differs from
root@letux:~# echo -1 >/sys/bus/platform/drivers/omap_hdq/480b2000.1w/power/autosuspend_delay_ms
[ 544.714904] omap_hdq 480b2000.1w: omap_hdq_runtime_resume
root@letux:~# time cat /sys/class/power_supply/bq27000-battery/uevent
[ 551.704498] omap_hdq 480b2000.1w: hdq_read_byte
BR,
Nikolaus
root@letux:~# dmesg|fgrep hdq
[ 18.355163] omap_hdq 480b2000.1w: omap_hdq_runtime_resume
[ 18.432403] omap_hdq 480b2000.1w: OMAP HDQ Hardware Rev 0.5. Driver in Interrupt mode
[ 18.745269] omap_hdq 480b2000.1w: hdq_read_byte
[ 19.163055] omap_hdq 480b2000.1w: hdq_read_byte
[ 19.583099] omap_hdq 480b2000.1w: hdq_read_byte
[ 20.003051] omap_hdq 480b2000.1w: hdq_read_byte
[ 20.422973] omap_hdq 480b2000.1w: hdq_read_byte
[ 20.843109] omap_hdq 480b2000.1w: hdq_read_byte
[ 21.262908] omap_hdq 480b2000.1w: hdq_read_byte
[ 21.682922] omap_hdq 480b2000.1w: hdq_read_byte
[ 22.103149] omap_hdq 480b2000.1w: hdq_read_byte
[ 22.523040] omap_hdq 480b2000.1w: hdq_read_byte
[ 22.963012] omap_hdq 480b2000.1w: hdq_read_byte
[ 23.390197] omap_hdq 480b2000.1w: hdq_read_byte
[ 23.812988] omap_hdq 480b2000.1w: hdq_read_byte
[ 24.232971] omap_hdq 480b2000.1w: hdq_read_byte
[ 24.653167] omap_hdq 480b2000.1w: hdq_read_byte
[ 25.073028] omap_hdq 480b2000.1w: hdq_read_byte
[ 25.493011] omap_hdq 480b2000.1w: hdq_read_byte
[ 25.923095] omap_hdq 480b2000.1w: hdq_read_byte
[ 26.133392] omap_hdq 480b2000.1w: hdq_read_byte
[ 26.553009] omap_hdq 480b2000.1w: hdq_read_byte
[ 26.973083] omap_hdq 480b2000.1w: hdq_read_byte
[ 27.393035] omap_hdq 480b2000.1w: hdq_read_byte
[ 27.813354] omap_hdq 480b2000.1w: hdq_read_byte
[ 28.233367] omap_hdq 480b2000.1w: hdq_read_byte
[ 28.673309] omap_hdq 480b2000.1w: hdq_read_byte
[ 29.093322] omap_hdq 480b2000.1w: hdq_read_byte
[ 29.513366] omap_hdq 480b2000.1w: hdq_read_byte
[ 29.948089] omap_hdq 480b2000.1w: hdq_read_byte
[ 30.403076] omap_hdq 480b2000.1w: hdq_read_byte
[ 30.823303] omap_hdq 480b2000.1w: hdq_read_byte
[ 31.243408] omap_hdq 480b2000.1w: hdq_read_byte
[ 31.663085] omap_hdq 480b2000.1w: hdq_read_byte
[ 32.083312] omap_hdq 480b2000.1w: hdq_read_byte
[ 32.503326] omap_hdq 480b2000.1w: hdq_read_byte
[ 32.923309] omap_hdq 480b2000.1w: hdq_read_byte
[ 33.343353] omap_hdq 480b2000.1w: hdq_read_byte
[ 33.763305] omap_hdq 480b2000.1w: hdq_read_byte
[ 33.814392] Modules linked in: wl18xx wlcore mac80211 cfg80211 libarc4 omapdrm cmac bnep panel_tpo_td028ttec1 pps_gpio snd_soc_simple_card snd_soc_simple_card_utils pps_core simple_bridge wwan_on_off snd_soc_omap_twl4030 snd_soc_w2cbw003_bt snd_soc_gtm601 display_connector generic_adc_battery pwm_bl pwm_omap_dmtimer omap_aes_driver crypto_engine omap_crypto wlcore_sdio omap3_isp videobuf2_dma_contig omap_sham videobuf2_memops videobuf2_v4l2 bq27xxx_battery_hdq bq27xxx_battery videobuf2_common omap2430 omap_hdq bmp280_spi snd_soc_omap_mcbsp snd_soc_ti_sdma ov9655 bmp280_i2c v4l2_fwnode bmp280 bmg160_i2c bmg160_core at24 tsc2007 videodev leds_tca6507 mc bno055 bmc150_magn_i2c bmc150_accel_i2c bmc150_magn bmc150_accel_core industrialio_triggered_buffer snd_soc_si47xx kfifo_buf phy_twl4030_usb musb_hdrc twl4030_pwrbutton twl4030_vibra snd_soc_twl4030 hci_uart btbcm twl4030_charger twl4030_madc industrialio input_polldev gnss_sirf bluetooth gnss ecdh_generic ecc ehci_omap omapdss omapdss_base
[ 34.363281] omap_hdq 480b2000.1w: hdq_read_byte
[ 34.783142] omap_hdq 480b2000.1w: hdq_read_byte
[ 35.203124] omap_hdq 480b2000.1w: hdq_read_byte
[ 35.623382] omap_hdq 480b2000.1w: hdq_read_byte
[ 36.043273] omap_hdq 480b2000.1w: hdq_read_byte
[ 36.463317] omap_hdq 480b2000.1w: hdq_read_byte
[ 36.883392] omap_hdq 480b2000.1w: hdq_read_byte
[ 37.303314] omap_hdq 480b2000.1w: hdq_read_byte
[ 37.723327] omap_hdq 480b2000.1w: hdq_read_byte
[ 38.143341] omap_hdq 480b2000.1w: hdq_read_byte
[ 38.563323] omap_hdq 480b2000.1w: hdq_read_byte
[ 38.983306] omap_hdq 480b2000.1w: hdq_read_byte
[ 39.403350] omap_hdq 480b2000.1w: hdq_read_byte
[ 39.823303] omap_hdq 480b2000.1w: hdq_read_byte
[ 40.243347] omap_hdq 480b2000.1w: hdq_read_byte
[ 40.663299] omap_hdq 480b2000.1w: hdq_read_byte
[ 41.083374] omap_hdq 480b2000.1w: hdq_read_byte
[ 41.503295] omap_hdq 480b2000.1w: hdq_read_byte
[ 41.923400] omap_hdq 480b2000.1w: hdq_read_byte
[ 42.343292] omap_hdq 480b2000.1w: hdq_read_byte
[ 42.763305] omap_hdq 480b2000.1w: hdq_read_byte
[ 43.183319] omap_hdq 480b2000.1w: hdq_read_byte
[ 43.603332] omap_hdq 480b2000.1w: hdq_read_byte
[ 44.188964] omap_hdq 480b2000.1w: omap_hdq_runtime_suspend
root@letux:~# time cat /sys/class/power_supply/bq27000-battery/uevent
[ 383.654083] omap_hdq 480b2000.1w: omap_hdq_runtime_resume
[ 383.868103] omap_hdq 480b2000.1w: hdq_read_byte
[ 384.288055] omap_hdq 480b2000.1w: hdq_read_byte
[ 384.708129] omap_hdq 480b2000.1w: hdq_read_byte
[ 385.128173] omap_hdq 480b2000.1w: hdq_read_byte
[ 385.548156] omap_hdq 480b2000.1w: hdq_read_byte
[ 385.968139] omap_hdq 480b2000.1w: hdq_read_byte
[ 385.973052] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.200683] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.215606] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.223358] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.241729] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.251129] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.260986] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.272460] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.281402] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.286865] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.510711] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.526153] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.533905] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.551818] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.561065] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.570922] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.582641] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.591339] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.602508] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.610900] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.620941] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.632476] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.641387] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.652709] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.660949] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.671051] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.680908] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.691986] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.701324] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.709045] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.720886] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.731872] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.741424] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.749053] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.761413] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.768798] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.780853] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.791839] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.801635] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.808746] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.820831] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.828124] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.840362] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.847534] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.859680] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.866882] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.882263] omap_hdq 480b2000.1w: hdq_read_byte
POWER_SUPPLY_NAME=bq27000-battery
POWER_SUPPLY_STATUS=Discharging
POWER_SUPPLY_PRE[ 386.897064] omap_hdq 480b2000.1w: hdq_read_byte
SENT=1
POWER_SUPPLY_VOLTAGE_NOW=4017000
POWER_SUPPLY_CURRENT_NOW=226873
POWER_SUPPLY_CAPACITY=83
POWER_SUPPL[ 386.911407] omap_hdq 480b2000.1w: hdq_read_byte
Y_CAPACITY_LEVEL=Normal
POWER_SUPPLY_TEMP=-2731
POWER_SUPPLY_T[ 386.922393] omap_hdq 480b2000.1w: hdq_read_byte
IME_TO_EMPTY_NOW=900
POWER_SUPPLY_TIME_TO_EMPTY_AVG=10860
POWER_SUPPLY_TECHNOLOGY=Li-ion
POWER_SUPPLY_CHARGE_FULL=858138
POW[ 386.937408] omap_hdq 480b2000.1w: hdq_read_byte
ER_SUPPLY_CHARGE_NOW=716806
POWER_SUPPLY_CHARGE_FULL_DESIGN=1233792
POWER_SUPPLY_CYCLE_COUNT=80
POWER_SUPPLY_[ 386.951812] omap_hdq 480b2000.1w: hdq_read_byte
ENERGY_NOW=2718520
POWER_SUPPLY_POWER_AVG=900820
POWER_SUPPLY_HEALTH=Good
POWER_SUPPLY_MANUFACTURER=Texas Instruments
real[ 386.968322] omap_hdq 480b2000.1w: hdq_read_byte
0m3.267s
user 0m0.002s
sys 0m0.230s
[ 386.981445] omap_hdq 480b2000.1w: hdq_read_byte
[ 386.991394] omap_hdq 480b2000.1w: hdq_read_byte
root@letux:~# [ 387.001861] omap_hdq 480b2000.1w: hdq_read_byte
[ 387.012512] omap_hdq 480b2000.1w: hdq_read_byte
[ 387.020996] omap_hdq 480b2000.1w: hdq_read_byte
[ 387.378234] omap_hdq 480b2000.1w: omap_hdq_runtime_suspend
root@letux:~#
root@letux:~# echo -1 >/sys/bus/platform/drivers/omap_hdq/480b2000.1w/power/autosuspend_delay_ms
[ 544.714904] omap_hdq 480b2000.1w: omap_hdq_runtime_resume
root@letux:~# time cat /sys/class/power_supply/bq27000-battery/uevent
[ 551.704498] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.711944] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.727844] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.735015] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.748260] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.755432] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.768615] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.775787] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.788604] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.795776] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.808715] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.815887] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.828735] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.839477] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.849578] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.859802] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.869720] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.879913] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.889739] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.899780] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.909667] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.919677] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.929748] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.939727] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.949768] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.959716] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.969787] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.979888] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.987060] omap_hdq 480b2000.1w: hdq_read_byte
[ 551.999176] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.007049] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.019042] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.026977] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.039184] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.046844] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.058288] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.065521] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.078613] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.085815] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.098785] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.106170] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.118682] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.126037] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.138702] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.146667] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.159271] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.166900] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.181365] omap_hdq 480b2000.1w: hdq_read_byte
POWER_SUPPLY_NAME=bq27000-battery
POWER_SUPPLY_STATUS=Discharging
POWER_SUPPLY_PRESENT=1
POWER_S[ 552.199462] omap_hdq 480b2000.1w: hdq_read_byte
UPPLY_VOLTAGE_NOW=4012000
POWER_SUPPLY_CURRENT_NOW=220447
POWE[ 552.210998] omap_hdq 480b2000.1w: hdq_read_byte
R_SUPPLY_CAPACITY=82
POWER_SUPPLY_CAPACITY_LEVEL=Normal
POWER_SUPPLY_TEMP=289
POWER_SUPPLY_TIME_TO_EMPTY_NOW=11580
POWER_SUPPLY_TIME_TO_EMPT[ 552.227203] omap_hdq 480b2000.1w: hdq_read_byte
Y_AVG=11040
POWER_SUPPLY_TECHNOLOGY=Li-ion
POWER_SUPPLY_CHARGE_FULL=858138
POWER_SUPPLY_CHARGE_NOW=706660
PO[ 552.241851] omap_hdq 480b2000.1w: hdq_read_byte
WER_SUPPLY_CHARGE_FULL_DESIGN=1233792
POWER_SUPPLY_CYCLE_COUNT=80
POWER_SUPPLY_ENERGY_NOW=2680560
POWER_SUPPLY_POWER_AVG=8760[ 552.257995] omap_hdq 480b2000.1w: hdq_read_byte
00
POWER_SUPPLY_HEALTH=Good
POWER_SUPPLY_MANUFACTURER=Texas In[ 552.269348] omap_hdq 480b2000.1w: hdq_read_byte
struments
real 0m0.510s
user 0m0.001s
sys 0m0.192s
root@letux:~# [ 552.286468] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.294067] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.305786] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.317443] omap_hdq 480b2000.1w: hdq_read_byte
[ 552.324645] omap_hdq 480b2000.1w: hdq_read_byte
