如何攻克 Android 调试难题？| 技术头条

作者 |小南瓜地瓜

责编 | 郭芮

最近在调试项目的亮屏速度，我们希望在按下power键后到亮屏这个时间能达到500MS以内，在Rockchip 3399和3288上面的时间都不能达到要求，因此引发了一系列的调试之路。

计算按下power键到亮屏的时间

Android 唤醒时间统计

刚开始的时候，我只在android阶段统计时间，也能看到时间的差异，但是不是最准确的，我统计的时间日志如下：

01-1809:13:40.992683772DSurfaceControl:ExcessivedelayinsetPowerMode():743ms

01-1809:13:45.304683772DSurfaceControl:ExcessivedelayinsetPowerMode():757ms

01-1809:13:49.559683772DSurfaceControl:ExcessivedelayinsetPowerMode():725ms

01-1809:18:27.461683772DSurfaceControl:ExcessivedelayinsetPowerMode():741ms

01-1809:18:32.766683772DSurfaceControl:ExcessivedelayinsetPowerMode():743ms

01-1809:18:35.861683772DSurfaceControl:ExcessivedelayinsetPowerMode():745ms

01-1809:18:38.345683772DSurfaceControl:ExcessivedelayinsetPowerMode():733ms

Kernel从Power到亮屏的时间统计

后来同事中的精英古总在他的代码上加入了从按下Power键到亮屏的时间，直接通过printk打印，代码如下：

diff--gita/drivers/gpu/drm/panel/panel-simple.cb/drivers/gpu/drm/panel/panel-simple.c

oldmode100644

newmode100755

index17c3b94..2b39662

---a/drivers/gpu/drm/panel/panel-simple.c

+++b/drivers/gpu/drm/panel/panel-simple.c

@@-504,6+504,7@@staticintpanel_simple_enable(structdrm_panel*panel)

}

p->enabled=true;

+printk("%sexit\n",__func__);

return0;

}

diff--gita/drivers/input/keyboard/rk_keys.cb/drivers/input/keyboard/rk_keys.c

oldmode100644

newmode100755

indexfed5ced..537b599

---a/drivers/input/keyboard/rk_keys.c

+++b/drivers/input/keyboard/rk_keys.c

@@-134,6+134,10@@staticvoidkeys_timer(unsignedlong_data)

key_dbg(pdata,"%skey[%s]:reportevent[%d]state[%d]\n",

button->type==TYPE_ADC?"adc":"gpio",

button->desc,button->code,button->state);

+if(strcmp(button->desc,"power")==0)

+printk("%skey[%s]:reportevent[%d]state[%d]\n",

+button->type==TYPE_ADC?"adc":"gpio",

+button->desc,button->code,button->state);

input_event(input,EV_KEY,button->code,button->state);

input_sync(input);

}

统计每个驱动的resume函数调用时间

上面的时间对我们调试非常有用，然后就需要细分到每个驱动的resume函数执行的时间，用的方法是我之前写过的，大概统计了下TP，LCD，sensor的resume时间，发现TP和LCD占用的时间非常多，然后跟同事一起看了下，同事把TP resume里面的代码用工作队列实现后速度明显有了提升。

然后有很长一段时间不知道干嘛，想打印其他每个驱动的resume时间，一直没找到方法，后面看到一个代码，非常有用。

kernel/drivers/base/power/main.c

staticvoiddpm_show_time(ktime_tstarttime,pm_message_tstate,char*info)

{

ktime_tcalltime;

u64usecs64;

intusecs;

calltime=ktime_get();

usecs64=ktime_to_ns(ktime_sub(calltime,starttime));

do_div(usecs64,NSEC_PER_USEC);

usecs=usecs64;

if(usecs==0)

usecs=1;

pr_info("PM:%s%s%sofdevicescompleteafter%ld.%03ldmsecs\n",

info?:"",info?"":"",pm_verb(state.event),

usecs/USEC_PER_MSEC,usecs%USEC_PER_MSEC);

}

这个函数用来打印resume的函数消耗的时间，但是如何去触发打印这个函数呢？

一定保证设备进入深度睡眠，串口也进入深度睡眠，没有任何打印后。

执行以下命令：

echoN>/sys/module/printk/parameters/console_suspend

//使控制台在suspend最后才关闭，这样可以打印出休眠过程完整信息

echo1>/sys/power/pm_print_times

//使能调试变量

打印的LOG类似下面的：

[37.031413]bcmsdh_sdmmc_resumeExit

[37.082174]PM:resumeofdevicescompleteafter78.589msecs

[37.085277][BT_RFKILL]:**disableirq

[37.087645]Restartingtasks...

修改Lcd配置减小resume时间

古总在调试过程中展现了非常厉害的功底，第一步就是修改了LCD的参数，让亮屏时间加快。修改如下：

---a/arch/arm/boot/dts/rk3288-pad.dts

+++b/arch/arm/boot/dts/rk3288-pad.dts

@@-169,10+169,10@@

dsi,lanes=<4>;

prepare-delay-ms=<20>;

-init-delay-ms=<20>;

-enable-delay-ms=<100>;

-disable-delay-ms=<20>;

-unprepare-delay-ms=<20>;

+//init-delay-ms=<20>;

+enable-delay-ms=<1>;

+disable-delay-ms=<1>;

+unprepare-delay-ms=<1>;

panel-init-sequence=[

1532028FA5

1501028300

修改DRM 超时时间减小唤醒时间

这是最关键的，DRM框架非常复杂，RK也是从开源的DRM移植过来使用，在DRM部分有个时间超时导致问题，最终跟RK拿到最新的patch让唤醒时间直接加速500MS。

我们在日志下发现问题，并给询问了RK，最终发现这部分代码没有更新到最新的部分。

hi rk:为什么亮屏的时候有时候会打印这句VOP等待超时？请问下这是什么意思。

[ 1211.293492] rockchip-vop ff930000.vop: wait win close timeout

[ 1211.293514] rockchip-vop ff930000.vop: [drm:vop_crtc_enable] Update mode to 1200*1920, close all win

有时候却不会打印。

[ 1216.423283] rockchip-vop ff930000.vop: [drm:vop_crtc_enable] Update mode to 12001920, close all win [ 1223.899741] rockchip-vop ff930000.vop: [drm:vop_crtc_enable] Update mode to 12001920, close all win

[ 1234.386252] rockchip-vop ff930000.vop: [drm:vop_crtc_enable] Update mode to 1200*1920, close all win

patch代码如下：

---a/drivers/gpu/drm/rockchip/rockchip_drm_vop.c

+++b/drivers/gpu/drm/rockchip/rockchip_drm_vop.c

@@-139,6+139,9@@

#defineto_vop_win(x)container_of(x,structvop_win,base)

#defineto_vop_plane_state(x)container_of(x,structvop_plane_state,base)

+/*addbyVENDOR_PATCHforseepupthedrmvopdriverat/1/18forRKDefect#191554,VENDOR_PATCHPAD100-193*/

+#defineVENDOR_PATCH

+

structvop_zpos{

intwin_id;

intzpos;

@@-868,9+871,15@@staticvoidvop_disable_all_planes(structvop*vop)

vop_disable_allwin(vop);

vop_cfg_done(vop);

+#ifdefVENDOR_PATCH

ret=readx_poll_timeout_atomic(vop_is_allwin_disabled,

vop,active,active,

+0,100*1000);

+#else

+ret=readx_poll_timeout_atomic(vop_is_allwin_disabled,

+vop,active,active,

0,500*1000);

+#endif

if(ret)

dev_err(vop->dev,"waitwinclosetimeout\n");

}

@@-2215,20+2224,36@@staticsize_tvop_crtc_bandwidth(structdrm_crtc*crtc,

u16htotal=adjusted_mode->crtc_htotal;

u16vdisplay=adjusted_mode->crtc_vdisplay;

intclock=adjusted_mode->crtc_clock;

+#ifndefVENDOR_PATCH

structvop*vop=to_vop(crtc);

conststructvop_data*vop_data=vop->data;

+#endif

structvop_plane_state*vop_plane_state;

structdrm_plane_state*pstate;

structvop_bandwidth*pbandwidth;

structdrm_plane*plane;

u64bandwidth;

inti,cnt=0;

+#ifdefVENDOR_PATCH

+intplane_num=0;

+#endif

if(!htotal||!vdisplay)

return0;

+#ifndefVENDOR_PATCH

pbandwidth=kmalloc_array(vop_data->win_size,sizeof(*pbandwidth),

GFP_KERNEL);

+#else

+for_each_plane_in_state(state,plane,pstate,i){

+if(pstate->crtc!=crtc||!pstate->fb)

+continue;

+plane_num++;

+}

+pbandwidth=kmalloc_array(plane_num,sizeof(*pbandwidth),

+GFP_KERNEL);

+#endif

+

if(!pbandwidth)

return-ENOMEM;

@@-2421,7+2446,10@@staticvoidvop_crtc_enable(structdrm_crtc*crtc)

rockchip_set_system_status(sys_status);

mutex_lock(&vop->vop_lock);

vop_initial(crtc);

-

+#ifdefVENDOR_PATCH

+vop_disable_allwin(vop);

+VOP_CTRL_SET(vop,standby,0);

+#endif

VOP_CTRL_SET(vop,dclk_pol,1);

val=(adjusted_mode->flags&DRM_MODE_FLAG_NHSYNC)?

0:BIT(HSYNC_POSITIVE);

@@-2549,8+2577,9@@staticvoidvop_crtc_enable(structdrm_crtc*crtc)

/*

*enablevop,alltheregisterwouldtakeeffectwhenvopexitstandby

*/

+#ifndefVENDOR_PATCH

VOP_CTRL_SET(vop,standby,0);

-

+#endif

enable_irq(vop->irq);

drm_crtc_vblank_on(crtc);

mutex_unlock(&vop->vop_lock);

修改QOS相关代码

QOS为Quality Of Service（服务质量）的简称，对PM QoS而言，表示Linux kernel电源管理相关的服务质量。那到底什么是服务质量呢？

我们知道，Linux PM的主要功能，是节省功耗，但同时，会付出一定的性能代价，例如延迟（latency）增加、吞吐量（throughput）下降。可以把PM当作一种服务，把它对性能的影响，类比为服务的质量（QoS）。对性能的影响越大，QoS越低，反之越高。

我们可以这么认为，我们在某个时候需要增加代码的执行速度，就通过这个去控制CPU的运行策略，这样确保代码可以快速执行。

不过这个方法没有使用到，如果对某个resume时间不是十分满意，可以尝试这个方法。

休眠唤醒流程图

从网上拷贝了个休眠唤醒的流程图，如果以后有问题需要分析的话，可以跟进这个流程去排查。

作者简介：韦启发，从事十余年嵌入式领域学习与工作，曾就职于TCL、中兴，从0开始创业开发过产品。目前在500强企业从事嵌入式系统软件开发工作。

本文系作者投稿，版权归作者所有。

热 文推 荐

☞拼多多否认损失 200 亿；董明珠回应再拼三年；特斯拉称“未来艰难” | 极客头条

为什么物联网产品迫切需要良好的 UI/UX 设计？

☞写高质量的代码，永不言晚！

☞V神说，解释以太坊2.0最好的文章就是这篇了

☞黄鳝门”视频女主播一审宣判！

☞Kafka学习笔记

☞12306能扛住明星出轨这种流量冲击吗？

☞心疼！能为程序员男友做些什么吗？

print_r('点个好看吧！');

var_dump('点个好看吧！');

NSLog(@"点个好看吧！");

System.out.println("点个好看吧！");

console.log("点个好看吧！");

print("点个好看吧！");

printf("点个好看吧！");

cout<<"点个好看吧！"<<endl;

Console.WriteLine("点个好看吧！");

fmt.Println("点个好看吧！");

Response.Write("点个好看吧！");

alert("点个好看吧！")

echo "点个好看吧！"

点击“阅读原文”，打开 CSDN App 阅读更贴心！

喜欢就点击“好看”吧