On 12/4/2018 8:45 AM, Jeffrey Hugo wrote:
On 12/4/2018 8:23 AM, Marc Gonzalez wrote:
On 03/12/2018 17:53, Marc Gonzalez wrote:
[ 0.970565] qcom-qmp-phy 1da7000.phy: Linked as a consumer to
regulator.15
[ 0.970676] qcom-qmp-phy 1da7000.phy: Linked as a consumer to
regulator.16
[ 0.971349] qcom-qmp-phy 1da7000.phy: Registered Qcom-QMP phy
[ 2.293324] ufshcd-qcom 1da4000.ufshc: ufshcd_populate_vreg:
Unable to find vdd-hba-supply regulator, assuming enabled
[ 2.355902] ufshcd-qcom 1da4000.ufshc: Linked as a consumer to
regulator.34
[ 2.359197] ufshcd-qcom 1da4000.ufshc: Linked as a consumer to
regulator.40
[ 2.365857] ufshcd-qcom 1da4000.ufshc: Linked as a consumer to
regulator.5
[ 2.400665] scsi host0: ufshcd
[ 2.435181] ufshcd-qcom 1da4000.ufshc: ufshcd_print_pwr_info:[RX,
TX]: gear=[1, 1], lane[1, 1], pwr[SLOWAUTO_MODE, SLOWAUTO_MODE], rate
= 0
[ 3.968211] ufshcd-qcom 1da4000.ufshc: ufshcd_query_flag: Sending
flag query for idn 1 failed, err = -11
[ 5.472133] ufshcd-qcom 1da4000.ufshc: ufshcd_query_flag: Sending
flag query for idn 1 failed, err = -11
[ 6.976114] ufshcd-qcom 1da4000.ufshc: ufshcd_query_flag: Sending
flag query for idn 1 failed, err = -11
[ 6.976387] ufshcd-qcom 1da4000.ufshc: ufshcd_query_flag_retry:
query attribute, opcode 6, idn 1, failed with error -11 after 3 retires
[ 6.984999] ufshcd-qcom 1da4000.ufshc: ufshcd_complete_dev_init
setting fDeviceInit flag failed with error -11
The PHY and MAC init *seem* successful, but obviously something goes
wrong,
since the query times out after 1500 ms, waiting for the completion in
ufshcd_wait_for_dev_cmd()
#define QUERY_REQ_TIMEOUT 1500 /* 1.5 seconds */
err is set to -ETIMEDOUT (i.e. -110) then the command is cleared for an
ulterior retry, and err is set to -EAGAIN (i.e. -11)
The question is: why does the command time out?
Enabling DEBUG...
[ 2.046246] ufshcd-qcom 1da4000.ufshc: ufshcd_populate_vreg: Unable
to find vdd-hba-supply regulator, assuming enabled
[ 2.046675] ufshcd-qcom 1da4000.ufshc: ufshcd_init_clocks: clk:
core_clk, rate: 198400000
[ 2.056101] ufshcd-qcom 1da4000.ufshc: ufshcd_init_clocks: clk:
bus_aggr_clk, rate: 198400000
[ 2.064333] ufshcd-qcom 1da4000.ufshc: ufshcd_init_clocks: clk:
iface_clk, rate: 0
[ 2.072820] ufshcd-qcom 1da4000.ufshc: ufshcd_init_clocks: clk:
core_clk_unipro, rate: 0
[ 2.080304] ufshcd-qcom 1da4000.ufshc: ufshcd_init_clocks: clk:
core_clk_ice, rate: 0
[ 2.088547] ufshcd-qcom 1da4000.ufshc: ufshcd_init_clocks: clk:
ref_clk, rate: 0
[ 2.096269] ufshcd-qcom 1da4000.ufshc: ufshcd_init_clocks: clk:
tx_lane0_sync_clk, rate: 0
[ 2.103743] ufshcd-qcom 1da4000.ufshc: ufshcd_init_clocks: clk:
rx_lane0_sync_clk, rate: 0
[ 2.111812] ufshcd-qcom 1da4000.ufshc: ufshcd_init_clocks: clk:
rx_lane1_sync_clk, rate: 0
[ 2.120178] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
core_clk enabled
[ 2.128292] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
bus_aggr_clk enabled
[ 2.135848] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
iface_clk enabled
[ 2.143833] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
core_clk_unipro enabled
[ 2.151831] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
core_clk_ice enabled
[ 2.160312] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
ref_clk enabled
[ 2.167789] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
tx_lane0_sync_clk enabled
[ 2.175444] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
rx_lane0_sync_clk enabled
[ 2.184043] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
rx_lane1_sync_clk enabled
[ 2.201054] ufshcd-qcom 1da4000.ufshc: Linked as a consumer to
regulator.34
[ 2.204116] ufshcd-qcom 1da4000.ufshc: Linked as a consumer to
regulator.40
[ 2.210800] ufshcd-qcom 1da4000.ufshc: Linked as a consumer to
regulator.5
The zero clock rates look suspicious, don't they?
[ 2.255243] ufshcd-qcom 1da4000.ufshc: ufshcd_print_pwr_info:[RX,
TX]: gear=[1, 1], lane[1, 1], pwr[SLOWAUTO_MODE, SLOWAUTO_MODE], rate = 0
[ 2.256240] ufshcd_wait_for_dev_cmd: time_left=8
[ 2.266734] ufshcd_wait_for_dev_cmd = 0
This command succeeds.
[ 3.780315] ufshcd_wait_for_dev_cmd: time_left=0
[ 3.780484] ufshcd-qcom 1da4000.ufshc: ufshcd_wait_for_dev_cmd:
dev_cmd request timedout, tag 31
[ 3.784258] ufshcd_wait_for_dev_cmd = -11
[ 3.792949] ufshcd-qcom 1da4000.ufshc: ufshcd_query_flag: Sending
flag query for idn 1 failed, err = -11
[ 3.796936] ufshcd-qcom 1da4000.ufshc: ufshcd_query_flag_retry:
failed with error -11, retries 0
[ 3.872239] ufshcd-qcom 1da4000.ufshc: ufshcd_update_uic_error: UIC
error flags = 0x00000000
[ 3.935871] ufshcd-qcom 1da4000.ufshc: ufshcd_update_uic_error: UIC
error flags = 0x00000000
[ 4.006340] ufshcd-qcom 1da4000.ufshc: ufshcd_update_uic_error: UIC
error flags = 0x00000001
[ 5.316263] ufshcd_wait_for_dev_cmd: time_left=0
[ 5.316406] ufshcd-qcom 1da4000.ufshc: ufshcd_wait_for_dev_cmd:
dev_cmd request timedout, tag 31
[ 5.320177] ufshcd_wait_for_dev_cmd = -11
[ 5.328838] ufshcd-qcom 1da4000.ufshc: ufshcd_query_flag: Sending
flag query for idn 1 failed, err = -11
[ 5.332872] ufshcd-qcom 1da4000.ufshc: ufshcd_query_flag_retry:
failed with error -11, retries 1
[ 6.852272] ufshcd_wait_for_dev_cmd: time_left=0
[ 6.852415] ufshcd-qcom 1da4000.ufshc: ufshcd_wait_for_dev_cmd:
dev_cmd request timedout, tag 31
[ 6.856185] ufshcd_wait_for_dev_cmd = -11
[ 6.864846] ufshcd-qcom 1da4000.ufshc: ufshcd_query_flag: Sending
flag query for idn 1 failed, err = -11
[ 6.868872] ufshcd-qcom 1da4000.ufshc: ufshcd_query_flag_retry:
failed with error -11, retries 2
[ 6.878415] ufshcd-qcom 1da4000.ufshc: ufshcd_query_flag_retry:
query attribute, opcode 6, idn 1, failed with error -11 after 3 retires
[ 6.887258] ufshcd-qcom 1da4000.ufshc: ufshcd_complete_dev_init
setting fDeviceInit flag failed with error -11
[ 6.900929] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
core_clk disabled
[ 6.909171] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
bus_aggr_clk disabled
[ 6.917054] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
iface_clk disabled
[ 6.925112] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
core_clk_unipro disabled
[ 6.932849] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
core_clk_ice disabled
[ 6.941305] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
ref_clk disabled
[ 6.949346] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
tx_lane0_sync_clk disabled
[ 6.956721] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
rx_lane0_sync_clk disabled
[ 6.965405] ufshcd-qcom 1da4000.ufshc: __ufshcd_setup_clocks: clk:
rx_lane1_sync_clk disabled
It's strange that one command succeeds, and the 3 next fail...
Maybe they don't speak to the same HW block...
Throwing something at a wall and seeing if it sticks....
The downstream MTP dtsi has -
&ufsphy1 {
vdda-phy-supply = <&pm8998_l1>;
vdda-pll-supply = <&pm8998_l2>;
vddp-ref-clk-supply = <&pm8998_l26>;
vdda-phy-max-microamp = <51400>;
vdda-pll-max-microamp = <14600>;
vddp-ref-clk-max-microamp = <100>;
vddp-ref-clk-always-on;
status = "ok";
};
&ufs1 {
vdd-hba-supply = <&gdsc_ufs>;
vdd-hba-fixed-regulator;
vcc-supply = <&pm8998_l20>;
vccq-supply = <&pm8998_l26>;
vccq2-supply = <&pm8998_s4>;
vcc-max-microamp = <750000>;
vccq-max-microamp = <560000>;
vccq2-max-microamp = <750000>;
status = "ok";
};
The *-max-microamp fields are basically load values that the downstream
driver sets on the regulators to ensure they are in a performance mode
before the driver attempts normal operation.
On the corresponding regulators in the mtp dtsi, you might try adding
regulator-allow-set-load;
regulator-system-load = <X>;
It might be that the regulators act as pull ups on some of the
signal/data lines, and by default they are not being driven hard enough
to do that job properly, resulting in the timeouts you see.
Nevermind, the mainline driver actually does this. Although I suppose
out of paranoia, you could double check that the load is being set on
the regulator as expected. IIRC, you can do that in sysfs.
--
Jeffrey Hugo
Qualcomm Datacenter Technologies as an affiliate of Qualcomm
Technologies, Inc.
Qualcomm Technologies, Inc. is a member of the
Code Aurora Forum, a Linux Foundation Collaborative Project.
