通话过程中屏幕点亮很慢的原因分析
发布日期:2021-07-29 10:44:36 浏览次数:0 分类:技术文章



问题描述:

用户接通电话后,遮挡接近传感器,屏幕关闭。当用户移开遮挡后发现屏幕再次点亮的时间较慢,约1s以上。用户感觉很不爽。因为别人的手机明显别这要快。

有户怀疑是p-sensor反应慢引起的。所以问题交给了我。

虽然我知道这一定和p-sensor没什么关系。(因为 P 已经被我调教的很到位了。。)

本着迎难而上的无畏精神。。。

我昨晚仔细思考了以下,终于搞定!

以下是我给出的结论。。直接粘过来吧。呵呵

========================================================================

分析:

打电话过程中,当用户遮挡P-sensor时,系统的early_suspend流程开始动作,调
用各类设备注册的early_suspend函 数,有些设备在该函数中可动有休眠或者断电
动作。
当用户移开遮挡时,系统的late_resume流程开始动作,调用各类设备注册的
late_resume函数,很多设备在这个函数中可能会有 init操作,因此,可能会包含
延时。

根本原因:
该问题是由于late_resume过程中的相关调用延时所致。
唤醒过程总耗时1196 ms,用户必然感觉很慢。
上述标记处(附件文档)需要找相关工程师确认,看能否在late_resume调用过程中减少延时。 
尤其是影响较大的BEKEN_FM 模块400ms, lcd_hx8362_rgb_spi 模块264ms, 电容 
屏模块158ms, mmc累计也达150ms

建议:
考虑部分模块是否有必要注册early_suspend流程。
部分模块的late_resume过程是否需要重新初始化,是否可避免。


顺便说下,这个问题和P-sensor没有丝毫关系。。。。。。

=================================================================================

log分析过程:


<3>0[ 118.759537] yasin test late resume START...******************************************

<4>0[ 118.759652] late_resume: calling ltr558_late_resume

<6>0[ 118.759697] [LTR588_INFO] ltr558_late_resume

<4>0[ 118.759741] late_resume: calling ltr558_late_resume done

<4>0[ 118.759800] late_resume: calling xxxxfb_late_resume

<4>0[ 118.759846] xxxxfb: [xxxxfb_late_resume]

<6>0[ 118.759887] xxxxfb:[xxxxfb_dispc_resume], dev->enable= 0

<6>0[ 118.759955] xxxxfb:[xxxxfb_dispc_resume] not from deep sleep

<6>0[ 118.760007] xxxxfb:[xxxxfb_panel_resume], dev->enable= 0,from_deep_sleep = 1

<4>0[ 118.760176] xxxxFB [SPI_ClkSetting], clk src is 0 clk div is 0

<4>0[ 118.760184]

12ms

<6>1[ 118.772852] [LTR588_INFO] ltr558_als_enable, gainrange=2, ret = 1

<3>1[ 118.774653] Kb_SetBackLightBrightness: Set KPLED_CTL : 0x1020

<3>1[ 118.774664]

136ms

<6>1[ 118.910688] request_suspend_state: wakeup (0->0) at 118901435212(2012-01-01 00:02:59.034057661 UTC)

50ms

<4>1[ 118.960943] hx8362_init

264ms lcd_hx8362_rgb_spi

<4>1[ 119.224490] RTL871X: module init start version:v4.1.3_6228.20121226

<4>1[ 119.224621] clock:0, host->clock:0, AHB_CTL0:0x1a400160

<4>1[ 119.224677] clock:0, host->clock:0, SDHCI_CLOCK_CONTROL:0x0

<3>1[ 119.224740] _regulator_get: get() with no identifier

<3>1[ 119.224788] mmc2: no vmmc regulator found

<4>1[ 119.224830] mmc2, power:12, set regulator voltage:3000000

17ms

<4>1[ 119.241441] ******* mmc2, call clk_enable*******

<4>1[ 119.241524] clock:400000, host->clock:0, AHB_CTL0:0x1a480160

<4>1[ 119.241577] clock:400000, host->clock:0, SDHCI_CLOCK_CONTROL:0x0

25ms

<4>1[ 119.266095] sdhci_bus_scan, entry

<4>1[ 119.266154] clock:1, host->clock:400000, AHB_CTL0:0x1a480160

<4>1[ 119.266206] clock:1, host->clock:400000,SDHCI_CLOCK_CONTROL:0x2007

<7>1[ 119.266261] sdhci: =========== REGISTER DUMP (mmc2)===========


AHB_CTL0:0x1a480160

<4>1[ 119.267008] INTC0_EN:0xe4184c4

<4>1[ 119.267040] INTC1_EN:0x3c4058

<4>1[ 119.267072] GIC_INT_EN:0xffff

<4>1[ 119.267103] GIC_INT_EN:0x8e61c4c4

<4>1[ 119.267136] GIC_INT_EN:0x63c40d8

<4>1[ 119.267182] ANA_REG_GLB_LDO_PD_CTRL1:0x2019

<4>1[ 119.267228] ANA_REG_GLB_LDO_VCTRL4:0x9009

<7>1[ 119.267267] sdhci: ===========================================

<7>1[ 119.267323] sdhci: =========== REGISTER DUMP (mmc2)===========

<7>1[ 119.267375] sdhci: 0x00000000 | 0x00000000 | 0x00000000 | 0x00000000


<7>1[ 119.267977] sdhci: 0x00000000 | 0x00000000 | 0x00000000

AHB_CTL0:0x1a480160

<4>1[ 119.268065] INTC0_EN:0xe4184c4

<4>1[ 119.268097] INTC1_EN:0x3c4058

<4>1[ 119.268128] GIC_INT_EN:0xffff

<4>1[ 119.268159] GIC_INT_EN:0x8e61c4c4

<4>1[ 119.268192] GIC_INT_EN:0x63c40d8

<4>1[ 119.268232] ANA_REG_GLB_LDO_PD_CTRL1:0x2019

<4>1[ 119.268278] ANA_REG_GLB_LDO_VCTRL4:0x9009

<7>1[ 119.268317] sdhci: ===========================================

<6>0[ 119.268446] mmc2 mmc_rescan

<4>0[ 119.268623] mmc2: !!!!! error in sending cmd:7, int:0x10000, err:-110

<7>0[ 119.268682] sdhci: =========== REGISTER DUMP (mmc2)===========

<7>0[ 119.268735] sdhci: 0x00000000 | 0x00000000 | 0x00010000 | 0x071a0000


<7>0[ 119.269330] sdhci: 0x00000000 | 0x00000000 | 0x00000000

AHB_CTL0:0x1a480160

<4>0[ 119.269416] INTC0_EN:0xe4184c4

<4>0[ 119.269447] INTC1_EN:0x3c4058

<4>0[ 119.269478] GIC_INT_EN:0xffff

<4>0[ 119.269508] GIC_INT_EN:0x8e61c4c4

<4>0[ 119.269541] GIC_INT_EN:0x63440d8

<4>0[ 119.269581] ANA_REG_GLB_LDO_PD_CTRL1:0x2019

<4>0[ 119.269626] ANA_REG_GLB_LDO_VCTRL4:0x9009

<7>0[ 119.269663] sdhci: ===========================================

<4>1[ 119.269852] mmc2: !!!!! error in sending cmd:7, int:0x10000, err:-110

<7>1[ 119.269908] sdhci: =========== REGISTER DUMP (mmc2)===========

<7>1[ 119.269961] sdhci: 0x00000000 | 0x00000000 | 0x00010000 | 0x071a0000

<7>1[ 119.269970]


<7>1[ 119.270493]

<7>1[ 119.270559] sdhci: 0x00000000 | 0x00000000 | 0x00000000

AHB_CTL0:0x1a480160

<4>1[ 119.270644] INTC0_EN:0xe4184c4

<4>1[ 119.270676] INTC1_EN:0x3c4058

<4>1[ 119.270707] GIC_INT_EN:0xffff

<4>1[ 119.270738] GIC_INT_EN:0x8e61c4c4

<4>1[ 119.270771] GIC_INT_EN:0x63440d8

<4>1[ 119.270810] ANA_REG_GLB_LDO_PD_CTRL1:0x2019

<4>1[ 119.270855] ANA_REG_GLB_LDO_VCTRL4:0x9009

<7>1[ 119.270892] sdhci: ===========================================

4ms

<4>1[ 119.274599] mmc2: !!!!! error in sending cmd:7, int:0x10000, err:-110

<7>1[ 119.274672] sdhci: =========== REGISTER DUMP (mmc2)===========

<7>1[ 119.274725] sdhci: 0x00000000 | 0x00000000 | 0x00010000 | 0x071a0000


<7>1[ 119.275272]

<7>1[ 119.275339] sdhci: 0x00000000 | 0x00000000 | 0x00000000

AHB_CTL0:0x1a480160

<4>1[ 119.275426] INTC0_EN:0xe4184c4

<4>1[ 119.275458] INTC1_EN:0x3c4058

<4>1[ 119.275488] GIC_INT_EN:0xffff

<4>1[ 119.275519] GIC_INT_EN:0x8e61c4c4

<4>1[ 119.275552] GIC_INT_EN:0x63440d0

<4>1[ 119.275601] ANA_REG_GLB_LDO_PD_CTRL1:0x2019

<4>1[ 119.275653] ANA_REG_GLB_LDO_VCTRL4:0x9009

<7>1[ 119.275692] sdhci: ===========================================

<4>1[ 119.276854] mmc2: !!!!! error in sending cmd:7, int:0x10000, err:-110

<7>1[ 119.276922] sdhci: =========== REGISTER DUMP (mmc2)===========

<7>1[ 119.276977] sdhci: 0x00000000 | 0x00000000 | 0x00010000 | 0x071a0000


<7>1[ 119.277520]

<7>1[ 119.277586] sdhci: 0x00000000 | 0x00000000 | 0x00000000

AHB_CTL0:0x1a480160

<4>1[ 119.277673] INTC0_EN:0xe4184c4

<4>1[ 119.277704] INTC1_EN:0x3c4058

<4>1[ 119.277735] GIC_INT_EN:0xffff

<4>1[ 119.277766] GIC_INT_EN:0x8e61c4c4

<4>1[ 119.277799] GIC_INT_EN:0x63440d0

<4>1[ 119.277842] ANA_REG_GLB_LDO_PD_CTRL1:0x2019

<4>1[ 119.277888] ANA_REG_GLB_LDO_VCTRL4:0x9009

<7>1[ 119.277926] sdhci: ===========================================

<6>0[ 119.278384] mmc2: card 0001 removed

<7>0[ 119.278648] sdhci: =========== REGISTER DUMP (mmc2)===========

<7>0[ 119.278713] sdhci: 0x00000000 | 0x00000000 | 0x00010000 | 0x071a0000


<7>0[ 119.279254]

<7>0[ 119.279321] sdhci: 0x00000000 | 0x00000000 | 0x00000000

AHB_CTL0:0x1a480160

<4>0[ 119.279418] INTC0_EN:0xe4184c4

<4>0[ 119.279450] INTC1_EN:0x3c4058

<4>0[ 119.279481] GIC_INT_EN:0xffff

<4>0[ 119.279512] GIC_INT_EN:0x8e61c4c4

<4>0[ 119.279545] GIC_INT_EN:0x63c40d8

<4>0[ 119.279589] ANA_REG_GLB_LDO_PD_CTRL1:0x2019

<4>0[ 119.279635] ANA_REG_GLB_LDO_VCTRL4:0x9009

<7>0[ 119.279672] sdhci: ===========================================

<7>0[ 119.279727] sdhci: =========== REGISTER DUMP (mmc2)===========

<7>0[ 119.279779] sdhci: 0x00000000 | 0x00000000 | 0x00000000 | 0x00000000


<7>0[ 119.280376] sdhci: 0x00000000 | 0x00000000 | 0x00000000

AHB_CTL0:0x1a480160

<4>0[ 119.280462] INTC0_EN:0xe4184c4

<4>0[ 119.280493] INTC1_EN:0x3c4058

<4>0[ 119.280524] GIC_INT_EN:0xffff

<4>0[ 119.280555] GIC_INT_EN:0x8e61c4c4

<4>0[ 119.280587] GIC_INT_EN:0x63c40d8

<4>0[ 119.280627] ANA_REG_GLB_LDO_PD_CTRL1:0x2019

<4>0[ 119.280671] ANA_REG_GLB_LDO_VCTRL4:0x9009

<7>0[ 119.280709] sdhci: ===========================================

<4>0[ 119.280902] ******* mmc2, call clk_disable*******

<4>0[ 119.280956] clock:0, host->clock:0, AHB_CTL0:0x1a400160

<4>0[ 119.281008] clock:0, host->clock:0, SDHCI_CLOCK_CONTROL:0x0

<3>0[ 119.281061] _regulator_get: get() with no identifier

<3>0[ 119.281106] mmc2: no vmmc regulator found

<4>0[ 119.281144] mmc2, power:0, set regulator voltage:0

3ms

<4>0[ 119.283940] clock:0, host->clock:0, AHB_CTL0:0x1a400160

<4>0[ 119.284007] clock:0, host->clock:0, SDHCI_CLOCK_CONTROL:0x0

<3>0[ 119.284067] _regulator_get: get() with no identifier

<3>0[ 119.284113] mmc2: no vmmc regulator found

<4>0[ 119.284154] mmc2, power:12, set regulator voltage:3000000

17ms

<4>0[ 119.301280] ******* mmc2, call clk_enable*******

<4>0[ 119.301351] clock:400000, host->clock:0, AHB_CTL0:0x1a480160

<4>0[ 119.301403] clock:400000, host->clock:0, SDHCI_CLOCK_CONTROL:0x0

3ms

<6>1[ 119.304988] xxxxfb:[xxxxfb_dispc_resume], leave dev->enable= 1

<4>1[ 119.305068] late_resume: calling xxxxfb_late_resume done

<4>1[ 119.305124] late_resume: calling start_drawing_late_resume

4ms

<4>1[ 119.309534] late_resume: calling start_drawing_late_resume done

<4>1[ 119.309939] late_resume: calling ft5x0x_ts_resume

<4>1[ 119.310030] ==ft5x0x_ts_resume==

10ms

<4>0[ 119.321319] mmc2, ****************** sdhci_hw_reset, callmmc_power_off ***********

<7>0[ 119.321423] sdhci: =========== REGISTER DUMP (mmc2)===========

<7>0[ 119.321479] sdhci: 0x00000000 | 0x00000000 | 0x00000000 | 0x00000000


<7>0[ 119.322024]

<7>0[ 119.322092] sdhci: 0x00000000 | 0x00000000 | 0x00000000

AHB_CTL0:0x1a680160

<4>0[ 119.322181] INTC0_EN:0xe4184c4

<4>0[ 119.322213] INTC1_EN:0x3c4058

<4>0[ 119.322244] GIC_INT_EN:0xffff

<4>0[ 119.323330] GIC_INT_EN:0x8e61c4c4

<4>0[ 119.323368] GIC_INT_EN:0x63c40d8

<4>0[ 119.323417] ANA_REG_GLB_LDO_PD_CTRL1:0x2019

<4>0[ 119.323463] ANA_REG_GLB_LDO_VCTRL4:0x9009

<7>0[ 119.323501] sdhci: ===========================================

<7>0[ 119.323557] sdhci: =========== REGISTER DUMP (mmc2)===========

<7>0[ 119.323609] sdhci: 0x00000000 | 0x00000000 | 0x00000000 | 0x00000000


<7>0[ 119.324213]

<7>0[ 119.324283] sdhci: 0x00000000 | 0x00000000 | 0x00000000

AHB_CTL0:0x1a680160

<4>0[ 119.324369] INTC0_EN:0xe4184c4

<4>0[ 119.324401] INTC1_EN:0x3c4058

<4>0[ 119.324432] GIC_INT_EN:0xffff

<4>0[ 119.324462] GIC_INT_EN:0x8e61c4c4

<4>0[ 119.324495] GIC_INT_EN:0x63c40d8

<4>0[ 119.324535] ANA_REG_GLB_LDO_PD_CTRL1:0x2019

<4>0[ 119.324580] ANA_REG_GLB_LDO_VCTRL4:0x9009

<7>0[ 119.324618] sdhci: ===========================================

<4>0[ 119.324670] ******* mmc2, call clk_disable*******

<4>0[ 119.324721] clock:0, host->clock:0, AHB_CTL0:0x1a600160

<4>0[ 119.324768] clock:0, host->clock:0, SDHCI_CLOCK_CONTROL:0x0

<3>0[ 119.324821] _regulator_get: get() with no identifier

<3>0[ 119.324866] mmc2: no vmmc regulator found

<4>0[ 119.324904] mmc2, power:0, set regulator voltage:0

17ms

<4>0[ 119.341363] mmc2, ****************** sdhci_hw_reset, callmmc_power_up ***********

<4>0[ 119.341469] clock:0, host->clock:0, AHB_CTL0:0x1a600160

<4>0[ 119.341517] clock:0, host->clock:0, SDHCI_CLOCK_CONTROL:0x0

<3>0[ 119.341571] _regulator_get: get() with no identifier

<3>0[ 119.341616] mmc2: no vmmc regulator found

<4>0[ 119.341656] mmc2, power:12, set regulator voltage:3000000

20ms

<4>1[ 119.361502] ******* mmc2, call clk_enable*******

<4>1[ 119.361583] clock:400000, host->clock:0, AHB_CTL0:0x1a680160

<4>1[ 119.361635] clock:400000, host->clock:0, SDHCI_CLOCK_CONTROL:0x0

20ms

<4>1[ 119.381568] mmc2, ****************** sdhci_hw_reset, set cmd anddata***********

<4>1[ 119.381654] mmc2, ****************** sdhci_hw_reset ***********

7ms

<4>0[ 119.388885] clock:16000000, host->clock:400000,AHB_CTL0:0x1a680160

<4>0[ 119.388950] clock:16000000, host->clock:400000,SDHCI_CLOCK_CONTROL:0x2007

6ms

<6>0[ 119.394453] mmc2: new high speed SDIO card at address 0001

158ms 电容屏

<4>1[ 119.552293] late_resume: calling ft5x0x_ts_resume done

<4>1[ 119.552380] late_resume: calling xxxx_led_late_resume

<6>1[ 119.552427] xxxx_led_late_resume

<3>1[ 119.552504] Kb_SetBackLightBrightness: Set KPLED_CTL : 0x1020

<3>1[ 119.552513]

<4>1[ 119.552577] late_resume: calling xxxx_led_late_resume done

<4>1[ 119.552630] late_resume: calling beken_early_resume

<4>1[ 119.552676] beken_early_resume.

<6>1[ 119.552715] BEKEN_FM 2-0070: beken_resume, FM opened before suspend:0

<3>1[ 119.552773] BEKEN_FM 2-0070: FM chip open!!!!

<3>1[ 119.552815] BEKEN_FM 2-0070: FM open: bk1080_init!!!!

<6>1[ 119.553627] BEKEN_FM 2-0070: BK1080 id:0x1080

400ms Beken FM

<3>1[ 119.953873] BEKEN_FM 2-0070: FM open: FM is opened

<6>1[ 119.955144] BEKEN_FM 2-0070: FM close: beken will run standby.

<4>1[ 119.955211] late_resume: calling beken_early_resume done

<4>1[ 119.955270] late_resume: calling xxxx_backlight_late_resume

<6>1[ 119.955319] xxxx_backlight_late_resume

<3>1[ 119.955360] *********************************yasin test setbrightness = 102

<4>1[ 119.955422] late_resume: calling xxxx_backlight_late_resume done

<3>1[ 119.955473]

<3>1[ 119.955477]

<3>1[ 119.955481] yasin test late resume DONE...******************************************




唤醒过程总耗时1196ms,这就是屏幕点亮很慢的原因。

上述标记处需要找相关工程师确认,看能否在late_resume调用过程中减少延时。尤其是影响较大的BEKEN_FM模块400ms,lcd_hx8362_rgb_spi 模块264ms电容屏模块158msmmc累计也达150ms


上一篇:Sed与AWK入门教程之Sed篇
下一篇:Android实战技术: 用Dimension解决多屏幕适配的问题