您的位置:首页 > 其它

powersave debug

2013-09-13 09:49 218 查看
高通8960平台

1.判断手机是否进入睡眠,比较直观的方法是连接电源,按下电源键,察看电源上显示的电流。手机睡眠后,电流为2mA上下范围。

2.如果手机不睡眠,可以分为几个步骤去调查。

首先看一下正常的睡眠kernel log(kernel log里显示睡眠,只能说AP进入睡眠了):

<6>[ 101.044376] request_suspend_state: sleep (0->3) at 101051334996 (1970-01-14 20:59:46.142436583 UTC) /*开始请求睡眠:echo mem > /power/state*/

<6>[ 101.044437] [measure]early_suspend start /*调用early suspend,根据设备注册的顺序调用*/

<6>[ 101.179612] [measure]early_suspend end

<4>[ 101.887135] Freezing user space processes ... (elapsed 0.01 seconds) done. /*冻结用户空间进程*/

<4>[ 102.153090] Freezing remaining freezable tasks ... (elapsed 0.02 seconds) done.

<4>[ 102.173172] Suspending console(s) (use no_console_suspend to debug)

<4>[ 102.173172] [measure]dpm_suspend_start start /*调用设备注册的suspend函数*/

<6>[ 102.176041] dpm_suspend(): Executing suspend callbacks is started.

<6>[ 102.190202] PM: suspend of devices complete after 14.161 msecs

<4>[ 102.190202] [measure]dpm_suspend_start end

<6>[ 102.191637] PM: late suspend of devices complete after 1.434 msecs

<4>[ 102.191667] Disabling non-boot CPUs ... /*关闭不使用的CPU*/

<5>[ 102.193468] CPU1: msm_pm_cpu_enter_lowpower: shutting down cpu

<6>[ 102.193499] CPU1: msm_pm_power_collapse: idle 0

<6>[ 102.193499] CPU1: msm_pm_power_collapse: pre power down

<6>[ 102.193529] CPU1: msm_pm_power_collapse: change clock rate (old rate = 0)

<6>[ 102.193529] CPU1: msm_pm_spm_power_collapse: notify_rpm 1

<6>[ 102.193560] CPU1: msm_pm_spm_power_collapse: program vector to c0119574

<4>[ 102.194628] pm8xxx_irq_mask: masking rouge irq=512 pmirq=72

<6>[ 102.194842] msm_pm_enter /*调用对应平台的睡眠函数*/

<6>[ 102.194842] msm_pm_enter: power collapse

<6>[ 102.194842] msm_rpmrs_show_resources: resource pxo: buffered 1, value 0x0 /*资源的一些状态*/

<6>[ 102.194842] msm_rpmrs_show_resources: resource L2_cache: value 0

<6>[ 102.194842] msm_rpmrs_show_resources: resource vdd_mem: buffered 1, value 0x40800000

<6>[ 102.194842] msm_rpmrs_show_resources: resource vdd_dig: buffered 1, value 0x4087a120

<6>[ 102.194842] msm_rpmrs_show_resources: resource rpm_ctl: buffered 0, value 0x0

<6>[ 102.194842] msm_mpm_irqs_detectable: cannot monitor 000000,00000000,00000000,00000000,00000000,00000000,00020000,00000000,00000000,00000000,00000000,00000000,00000000,00000000

<6>[ 102.194842] msm_pm_enter: limit c8c045e4: pxo 0, l2_cache 0, vdd_mem 750000, vdd_dig 750000

<6>[ 102.194842] msm_mpm_write: reg 0.0: 0x02000022 /*写寄存器*/

<6>[ 102.194842] msm_mpm_write: reg 1.0: 0x00000080

<6>[ 102.194842] msm_mpm_write: reg 2.0: 0x00000000

<6>[ 102.194842] msm_mpm_write: reg 3.0: 0xffffffff

<6>[ 102.194842] msm_mpm_write: reg 0.1: 0x00080200

<6>[ 102.194842] msm_mpm_write: reg 1.1: 0x00004000

<6>[ 102.194842] msm_mpm_write: reg 2.1: 0x00004200

<6>[ 102.194842] msm_mpm_write: reg 3.1: 0xffffffff

<6>[ 102.194842] CPU0: msm_pm_power_collapse: idle 0

<6>[ 102.194842] CPU0: msm_pm_power_collapse: pre power down

<6>[ 102.194842] CPU0: msm_pm_power_collapse: change clock rate (old rate = 1512000)

<6>[ 102.194842] CPU0: msm_pm_spm_power_collapse: notify_rpm 1 /*最终调用到SPM,通知RPM*/

<6>[ 102.194842] CPU0: msm_pm_spm_power_collapse: program vector to c0119898

<6>[ 102.194842] msm_pm_spm_power_collapse(): [CPU0] Enter suspend power collapse. /*真正进入睡眠*/

<6>[ 102.194842] msm_pm_spm_power_collapse(): [CPU0] Exit suspend power collapse. ret = 1 /*这里是唤醒后出现的log*/

<6>[ 102.194842] CPU0: msm_pm_spm_power_collapse: msm_pm_collapse returned, collapsed 1

<6>[ 102.194842] CPU0: msm_pm_power_collapse: restore clock rate to 1512000

<6>[ 102.194842] CPU0: msm_pm_power_collapse: post power up

<6>[ 102.194842] CPU0: msm_pm_power_collapse: return

<6>[ 102.194842] msm_mpm_exit_sleep: pending.0: 0x00000021

<6>[ 102.194842] msm_mpm_exit_sleep: pending.1: 0x00000000

<6>[ 102.194842] msm_mpm_write: reg 0.0: 0x00000000

<6>[ 102.194842] msm_mpm_write: reg 3.0: 0xffffffff

<6>[ 102.194842] msm_mpm_write: reg 0.1: 0x00000000

<6>[ 102.194842] msm_mpm_write: reg 3.1: 0xffffffff

<6>[ 102.194842] msm_pm_enter: return

<4>[ 102.194842] msm_gpio_show_resume_irq: 392 triggered/*唤醒的原因这里会显示*/

<4>[ 102.194842] gic_show_resume_irq: 48 triggered

<4>[ 102.194842] gic_show_resume_irq: 52 triggered





首先第一种情况,如果在log打印出来的信息最后到[measure]early_suspend end,这时候说明有相关的wakelock没有释放,这个wakelock有可能是内核空间的,也有可能是用户空间的。

首先,将内核空间的debug mask打开,我们可以看到内核各个wakelock的状态,察看是否都释放。如果看到有一个叫powermanagerservice的wakelock没释放的话,这就需要调查上层,因为powermanagerservice这个wakelock是在framework层申请的,可以在powermanagerservice.java中添加一些log看到所有wakelock的动作。

另外,还可以直接察看睡眠时候,wakelock的状态:

察看用户空间的wakelock:cat /sys/power/wake_lock

返回结果:PowerManagerService mrvl_aud_lock (表示正有这些wakelock没有释放)

察看内核空间的wakelock:cat /proc/wakelocks

返回结果:

name count expire_count wake_count active_since total_time sleep_time max_time last_change

"mrvl_aud_lock" 39 0 0 5137237548 692107604979 370840789798 230798461912 2779292228951

如果第四列wake_count的值不为0,表示这个wakelock没有释放。不过通常都会到powermanagerservice中将未释放的wakelock名字打出来。



调用到early_suspend时,加入如下log,会将所有注册的earlysuspend函数调用。

81 static void early_suspend(struct work_struct *work)

82 {

111 printk("[measure]early_susepend handler start: calling %pf\n", pos->suspend);

112 pos->suspend(pos);

printk("[measure]early_susepend handler end: calling%pf\n ", pos->suspend);

125 }

134 static void late_resume(struct work_struct *work)

135 {

printk(" [measure]late_resume handler start: calling %pf\n ", pos->resume);

pos->resume(pos);

printk(" [measure]late_resume handler start: calling %pf\n ", pos->resume);

125 }

效果如下:

early suspend:

<6>[ 101.044498] [measure]early_susepend handler start: calling stop_drawing_early_suspend

<6>[ 101.064703] [measure]early_susepend handler end: calling stop_drawing_early_suspend

<6>[ 101.064733] [measure]early_susepend handler start: calling kgsl_early_suspend_driver

<6>[ 101.070349] [measure]early_susepend handler end: calling kgsl_early_suspend_driver

<6>[ 101.070410] [measure]early_susepend handler start: calling msmfb_early_suspend

<6>[ 101.179490] [measure]early_susepend handler end: calling msmfb_early_suspend

late resume

1922 <4>[ 55.517289] [measure]late_resume handler start: calling cpufreq_gov_ondemand_late_resume

1923 <4>[ 55.517320] [measure]late_resume handler end: calling cpufreq_gov_ondemand_late_resume

1924 <4>[ 55.517350] [measure]late_resume handler start: calling msmsdcc_late_resume

1925 <4>[ 55.517381] [measure]late_resume handler end: calling msmsdcc_late_resume



其次,当调用到dpm_suspend_start,会逐个执行相应device的suspend函数,如果失败,也会显示那个设备阻止睡眠。

将drivers/base/platform.c中,

707 int platform_pm_suspend(struct device *dev)

708 {

709 struct device_driver *drv = dev->driver;

710 int ret = 0;

711

712 if (!drv)

713 return 0;

714

715 if (drv->pm) {

716 if (drv->pm->suspend)

717 ret = drv->pm->suspend(dev);/*在这里加入printk("%pf enter \n",drv->pm->suspend);将设备调用的suspend打印出来*/

718 } else {

719 ret = platform_legacy_suspend(dev, PMSG_SUSPEND);

720 }

721

722 return ret;

723 }

725 int platform_pm_resume(struct device *dev)

726 {

727 struct device_driver *drv = dev->driver;

728 int ret = 0;

729

730 if (!drv)

731 return 0;

732

733 if (drv->pm) {

734 if (drv->pm->resume)

735 ret = drv->pm->resume(dev);/*在这里加入printk("%pf enter \n",drv->pm->resume);将设备调用的resume打印出来*/

736 } else {

737 ret = platform_legacy_resume(dev);

738 }

739

740 return ret;

741 }

效果如下:

suspend:

1435 <4>[ 47.884632] msm_fb_ext_suspend end

1436 <4>[ 47.884816] msm_fb_ext_suspend start

1437 <4>[ 47.884846] msm_fb_ext_suspend end

1438 <4>[ 47.888234] msm_fb_ext_suspend start

1439 <4>[ 47.888264] msm_fb_ext_suspend end

1440 <4>[ 47.888356] extsdcc_pm_suspend start

1441 <4>[ 47.888386] extsdcc_pm_suspend end

1442 <4>[ 47.888448] msmsdcc_pm_suspend start

1443 <4>[ 47.904654] msmsdcc_pm_suspend end

resume:

1524 <4>[ 47.971768] wcnss_wlan_resume start

1525 <4>[ 47.971799] wcnss_wlan_resume end

1526 <4>[ 47.972256] tsens_resume start

1527 <4>[ 47.972318] tsens_resume end

1528 <4>[ 47.972470] msm_otg_pm_resume start

1529 <4>[ 47.972501] msm_otg_pm_resume end

1530 <4>[ 47.972562] ehci_msm_pm_resume start

1531 <4>[ 47.972623] ehci_msm_pm_resume end

1532 <4>[ 47.972897] kgsl_resume start

1533 <4>[ 47.972928] kgsl_resume end

接下来说一下mpm irq的监测:

<6>[ 102.194842] msm_mpm_irqs_detectable: cannot monitor 000000,00000000,00000000,00000000,00000000,00000000,00020000,00000000,00000000,00000000,00000000,00000000,00000000,00000000

|reg |IRQ_BITMAP|bit(=IRQ)|category|GPIO port number|
|[13]|  000000  |416:439  |GPIO    |128:151         |
|[12]|00000000  |384:415  |GPIO    |96:127          |
|[11]|00000000  |352:383  |GPIO    |64:95           |
|[10]|00000000  |320:351  |GPIO    |32:63           |
|[9] |00000000  |288:319  |GPIO    |0:31            |
|[8]:[0]|-      |0:187    |GIC     |-               |

如果这里显示有其他多的位,显示相应的中断存在,这就意味着krait可以进入睡眠,但是RPM不能进入VDD_MIN.

如下log中显示gpio99,gpio100,gpio101处于enable的状态
<6>[  102.961544] msm_mpm_irqs_detectable: cannot monitor 000000,00000038,00000000,00000000,00000000,00000000,
000a0081,06040000,00000000,00000345,00810955,5550001c,00000004,00100000





<6>[ 102.194842] msm_pm_enter: limit c8c045e4: pxo 0, l2_cache 0, vdd_mem 750000, vdd_dig 750000

这句log显示资源的状态,之前遇到过一个问题,RIVA没有上电,导致,这里的共享资源,尤其是 vdd_dig显示为最大值(12550000)。这样手机就一直不睡。





到这里的时候,其实还可以将睡眠前所有的GPIO,VREG,CLOCK的状态打印出来,看一下状态是否正确:

打出的gpio状态:

在调用SPM睡眠前加log,或者使用trace32脚本gpio_dump.cmm:

GPIO[0.] [FS] 0x0 [DIR] I [PULL] PD [DRV] 2mA [VAL] L [INT_EN] DIS [INT_TRG] HIGH LEVEL [INT_RAW_STAT] 0x0

和正确的gpio状态对比,察看哪里有不同。

打出的clock状态,睡眠前:

echo 1 > /sys/kernel/debug/clk/debug_suspend

<4>[ 70.455150] Disabling non-boot CPUs ...

<6>[ 70.457805] Enabled clocks:

<6>[ 70.457805] pxo_a_clk

<6>[ 70.457805] afab_a_clk

<6>[ 70.457805] cfpb_a_clk

<6>[ 70.457805] ebi1_a_clk

<6>[ 70.457805] mmfpb_a_clk

<6>[ 70.457805] cfpb_a_clk

<6>[ 70.457805] pmem_clk

<6>[ 70.457805] dma_bam_p_clk

<6>[ 70.457805] Enabled clock count: 8

<6>[ 70.457805] msm_mpm_irqs_detectable: cannot monitor 000000,00000000,00000000,00000000,00000000,00000000,00020000,00000000,00000000,00000000,00000000,00000000,00000000,00000000

而clock出错的情况下:

<6>[ 112.950618] Enabled clocks:

<6>[ 112.950618] pxo_a_clk [27000000]

<6>[ 112.950618] pxo_clk [27000000]

<6>[ 112.950618] pll8_clk [384000000] -> pxo_clk [27000000]

<6>[ 112.950618] afab_a_clk [492000000]

<6>[ 112.950618] cfpb_a_clk [32000000]

<6>[ 112.950618] ebi1_a_clk [492000000]

<6>[ 112.950618] mmfpb_a_clk [38400000]

<6>[ 112.950618] sfab_a_clk [54000000]

<6>[ 112.950618] afab_msmbus_a_clk [492000000] -> afab_a_clk [492000000]

<6>[ 112.950618] cfpb_a_clk [32000000]

<6>[ 112.950618] ebi1_msmbus_a_clk [492000000] -> ebi1_a_clk [492000000]

<6>[ 112.950618] mmfpb_a_clk [38400000]

<6>[ 112.950618] cfpb_a_clk [32000000]

<6>[ 112.950618] pmem_clk [0]

<6>[ 112.950618] dma_bam_p_clk [0]

<6>[ 112.950618] mdp_clk [85330000, 1] -> pll8_clk [384000000] -> pxo_clk [27000000]

<6>[ 112.950618] mdp_clk [85330000, 1] -> pll8_clk [384000000] -> pxo_clk [27000000]

<6>[ 112.950618] mdp_vsync_clk [27000000, 1] -> pxo_clk [27000000]

<6>[ 112.950618] mdp_vsync_clk [27000000, 1] -> pxo_clk [27000000]

<6>[ 112.950618] lut_mdp_clk [0] -> mdp_clk [85330000, 1] -> pll8_clk [384000000] -> pxo_clk [27000000]

<6>[ 112.950618] lut_mdp_clk [0] -> mdp_clk [85330000, 1] -> pll8_clk [384000000] -> pxo_clk [27000000]

<6>[ 112.950618] mdp_axi_clk [0]

<6>[ 112.950618] mdp_p_clk [0]

<6>[ 112.950618] mdp_p_clk [0] /*MDP clock没有关掉*/

<6>[ 112.950618] mdp_axi_clk [0]

<6>[ 112.950618] mdp_axi_clk [0]

<6>[ 112.950618] mdp_axi_clk [0]

<6>[ 112.950618] Enabled clock count: 27

<6>[ 112.950618] msm_mpm_irqs_detectable: cannot monitor 000000,00000000,00000000,00000000,00000000,00000000,00020000,00000000,00000000,00000000,00000000,00000000,00000000,00000000



还可以通过log来察看各路电的状态:

echo 15 > sys/module/rpm_regulator/parameters/debug_mask

<6>[ 316.510819] rpm_regulator_vote: vote received 8921_s3 : voter=3, set=A, v_voter= 950000 uV, v_aggregate=1050000 uV

<6>[ 316.510849] rpm_regulator_duplicate: ignored request 8921_s3 : set=A; req[0]={131, 0x40900590}, req[1]={132, 0x04800064}

<6>[ 316.514024] rpm_regulator_vote: vote received 8921_s3 : voter=0, set=S, v_voter= 500000 uV, v_aggregate= 950000 uV

<6>[ 316.514085] rpm_regulator_req: buffered 8921_s3 : s=S, v= 950000 uV, ip= 100 mA, fm=none (0), pc= none (0), pf=none (4), pd=Y (1), ia= 0 mA, freq=4.80 MHz ( 4), pm=PWM (1), clk_src=0; req[0]={131, 0x408E7EF0}, req[1]={132, 0x04800064}







3.真正判断手机整体是否进入睡眠,可以察看节点:

mount -t debugfs none /sys/kernel/debug

cat /sys/kernel/debug/rpm_stats

RPM Mode:xo shutdown
Count:0
RPM Mode:xo shutdown
Total time(uSec):0
RPM Mode:vdd min
Count:0
RPM Mode:vdd min
Total time(uSec):0
得到的结果会显示RPM进入了多少次VDD_MIN,如果Count为0,表示手机整体并没有进入睡眠状态。

如果手机没有进入睡眠状态,这个时候可以去察看RPM log,看为什么没有进入睡眠.

mount -t debugfs none /sys/kernel/debug

cat /sys/kernel/debug/rpm_log > /data/rpm.ulog

adb pull /data/rpm.ulog .

取出rpm log一个方法是使用debugfs,如上所示。

一个方法是使用trace32连接上手机,取下dump,之后通过解析得到rpm log。

d.save.binary C;\CODERAM.bin 0x20000++0x24000

d.save.binary C;\MSGRAM.bin 0x108000++0x5FFF

d.load.binary C;\CODERAM.bin 0x20000

d.load.binary C;\MAGRAM.bin 0x20000

d.load.elf RPM.elf /nocode /noclear ------------[1]

do ulog.cmm 这里会生成rpm log

生成的rpmlog为二进制,需要转化为文本文件察看:

python rpm_log.py "rpm.ulog" > parse_rpm.log

如果log中没有出现:

304.719299: rpm_shutdown_req (master: "MSS") (core: 0)

304.719330: rpm_shutdown_ack (master: "MSS") (core: 0)

304.720123: rpm_master_set_transition (master: "MSS") (leaving: "Active Set") (entering: "Sleep Set")

表示modem已经进入睡眠或者modem没有进入睡眠。如果log抓的全的话,上面log肯定会出现的。

如果想察看具体的数据信息,需要抓取npa log。

经过[1]

do rpm_loadcoredump.cmm 得到栈信息

v.v gpRPMFWMaster 此结构里保存着各个核的状态

typedef struct

51 {

52 /* basic information required at various points */

53 DAL_rpmfw_MasterType master_id;

54

55 /* configuration set data */

56 DAL_rpm_ConfigSetType selected_set;

57 DAL_rpmfw_ConfigSetDataType set[DAL_RPM_CONFIG_SET_COUNT];

58

59 /* spm handshake data */

60 DAL_rpmfw_SPMStatusType spm_subsystem_status;

61 uint32 spm_num_active_cores;

62 uint32 spm_pending_bringups;

63

64 /* 'tasks' for each master */

65 RPMFWRequestHandler *handler;

66 RPMFWSetChanger *changer;

67 } DAL_rpmfw_MasterDataType;

gpRPMFWMaster数据的介绍:

gpRPMFWMaster[0]-----APPS

gpRPMFWMaster[1]-----MODEM SW

gpRPMFWMaster[2]-----LPASS

gpRPMFWMaster[3]-----RIVA

gpRPMFWMaster[4]-----DSPS

dpRPMFWMaster[5]-----MODEM FW

selected_set:

0x0:DAL_RPM_CONFIG_SET_PRIMARY

0x1:DAL_RPM_CONFIG_SET_SLEEP















下面说一下,手机被唤醒时,产生的中断判断来自于那里时,怎样去调查?

<4>[ 102.194842] msm_gpio_show_resume_irq: 392 triggered

<4>[ 102.194842] gic_show_resume_irq: 48 triggered

<4>[ 102.194842] pm8xxx_irq_block_handler:518 triggered (9:6)

首先看一下,arch/arm/mach-msm/include/mach/irqs-8960.h,里面定义了MSM ACPU的中断数值。/*看第二行,表示中断触发,48表示TLMM*/

19 /* MSM ACPU Interrupt Numbers */

20

21 /* 0-15: STI/SGI (software triggered/generated interrupts)

22 16-31: PPI (private peripheral interrupts)

23 32+: SPI (shared peripheral interrupts) */

24

25 #define GIC_PPI_START 16

26 #define GIC_SPI_START 32



其次,看一下,arch/arm/mach-msm/include/mach/irqs.h:

41 #define NR_MSM_IRQS 288 /*msm8960上共有288个中断*/

42 #define NR_GPIO_IRQS 152 /*GPIO做中断有152个*/

43 #define NR_PM8921_IRQS 256 /*PMIC上的中断共256个*/

93 #define MSM_GPIO_TO_INT(n) (NR_MSM_IRQS + (n)) /*GPIO做中断,中断号在288之后;看log第一行,392-288=104,表明gpio104中断触发*/

92 #define NR_IRQS (NR_MSM_IRQS + NR_GPIO_IRQS + NR_BOARD_IRQS)

50 #define NR_BOARD_IRQS (NR_PM8921_IRQS + NR_PM8821_IRQS + \

51 NR_WCD9XXX_IRQS + NR_GPIO_EXPANDER_IRQS + NR_PCIE_MSI_IRQS)

最后看一下,./include/linux/mfd/pm8xxx/pm8921.h:

#define PM8921_IRQ_BLOCK_BIT(block, bit) ((block) * 8 + (bit)) /*PMIC具体算出的中断号,在传给GIC前,需要加上 NR_MSM_IRQS和NR_GPIO_IRQS即440;所以在log中打出block和bit还是比较直观能匹配出具体含义*/

#define PM8921_RTC_ALARM_IRQ PM8921_IRQ_BLOCK_BIT(4, 7) /*PMIC中断号具体所代表的含义;看第三行,9*8+6=78,表示ADC_EOC_USER_IRQ*/
内容来自用户分享和网络整理,不保证内容的准确性,如有侵权内容,可联系管理员处理 点击这里给我发消息
标签: