Linux下功耗测试开发初探
1、前言
Linux嵌入式设备开发，对于功耗要求较高。在遇到问题的时候，定位手段有限。
关于功耗一种是静态功耗，指的是某一种状态下的功耗情况，在这种状态下功耗尽量的低，比如suspended底电流越低越好、cpuidle的深睡和浅睡、cpu unplug等；
另一种是动态功耗，指的是各种状态的切换，比如susped-resume流程、cpuidle不同状态切换驻留时间、中断导致的唤醒频繁程度、wakelock导致的系统唤醒时长、在完成相同工作情况下cpufreq是否尽量低等等。
静态功耗的调试，可以在特定状态下测量功耗，逐步优化；
但是在动态功耗，也即系统运行时，影响功耗的因素千差万别，瞬息万变，就需要在测量功耗的时候抓住系统运行轨迹。
下面主要关注如何对功耗异常点进行定位，更快的发现异常点的原因。
2、内核功耗测试锚点
要测量功耗因素，就要了解那些内核行为导致了功耗增加或减少？具体需要抓住哪些轨迹，比如：
1. suspend-resume(何时进入suspend、持续时间、何时退出suspend、谁唤醒了系统)：machine_suspend----------成对出现 2. cpuidle(切换点、时长、状态)：cpuidle-----------------------------------------------------------成对出现 3. cpufreq(何时切换、切换到什么频点、持续多久)：cpu_frequency----------------------------------------单点 4. 中断(哪个中断、何时触发、中断函数处理耗时)：irq_handler_entry、irq_handler_exit--------------------成对出现 5. wakeup source()：wakeup_source_activate、wakeup_source_deactivate---------------------------成对出现 6. 电源域(哪个电源域、设置状态)：power_domain_target-----------------------------------------------成对出现 7. 时钟(哪个时钟、何时开、何时关、频率变动)：clock_enable、clock_disable、clock_set_rate--------------成对出现
其他轨迹：
8. 定时器(定时器创建、启动、超时、取消，包括低精度定时器和高精度定时器)：
8.1 低精度定时器(timer_init、timer_start、timer_cancel、timer_expire_entry、timer_expire_exit)-----------------成对出现
8.2 高精度定时器(hrtimer_init、hrtimer_start、hrtimer_expire_entry、hrtimer_expire_exit、hrtimer_cancel)-------成对出现 9. ...
可以把这些一个个Traceevents看做功耗信息锚点，下面逐个分析这些锚点。
除了每个锚点消息，一些公共信息比如：cpu id、pid、flags需要保留，以便分析。
flags：rqs-off、need-resched、hardirq/softirq、preempt-depth。
# entries-in-buffer/entries-written: 12876/12876 #P:1 # # _-----=> irqs-off-------------------'d'表示中断被disabled，'.'表示中断没有被关闭。 # / _----=> need-resched---------------'N'表示need_resched被设置，'.'表示need-resched没有被设置，中断返回不会进行进程切换 # | / _---=> hardirq/softirq------------'H'在softirq中发生了硬件中断，'h'表示硬中断，'s'表示软中断，'.'不在中断上下文中，普通状态。 # || / _--=> preempt-depth---------------当抢占中断使能后，该域代表preempt_disabled的级别。 # ||| / delay # TASK-PID CPU# |||| TIMESTAMP FUNCTION # | | | |||| | | <...>-1323 [000] d.h1 20.374237: irq_handler_entry: irq=41 name=zx29_i2c.0 <...>-1323 [000] dNh1 20.374237: irq_handler_exit: irq=41 ret=handled zte_usbCfgMng-760 [000] d... 20.374268: wakeup_source_deactivate: zx29-i2c state=0x284b0005 zte_usbCfgMng-760 [000] d... 20.374268: wakeup_source_activate: zx29-i2c state=0x284b0006 <...>-1327 [000] d.h. 20.374329: irq_handler_entry: irq=41 name=zx29_i2c.0 <...>-1327 [000] dNh. 20.374359: irq_handler_exit: irq=41 ret=handled <...>-1323 [000] d.h. 20.374420: irq_handler_entry: irq=41 name=zx29_i2c.0 <...>-1323 [000] dNh. 20.374420: irq_handler_exit: irq=41 ret=handled zte_usbCfgMng-760 [000] d... 20.374451: wakeup_source_deactivate: zx29-i2c state=0x284c0005 zte_usbCfgMng-760 [000] d... 20.374451: wakeup_source_activate: zx29-i2c state=0x284c0006 <...>-1323 [000] dNh. 20.374573: irq_handler_entry: irq=41 name=zx29_i2c.0 <...>-1323 [000] dNh. 20.374573: irq_handler_exit: irq=41 ret=handled
按照对功耗影响大小来排序，顺序应该是：suspend/resume最省电、其次是cpu hotplug、在某些情况下cpuidle也能达到cpu hotplug，再然后就是cpufreq的动态调压调频以及各种设备的RPM。
其他的情况还包括wakelock和中断，这些具体影响多少依情况变化很大。
2.1 trace_machine_suspend
suspend/resume的锚点位于suspend_devices_and_enter中：
int suspend_devices_and_enter(suspend_state_t state) { ... trace_machine_suspend(state); ... trace_machine_suspend(PWR_EVENT_EXIT); ... }
在suspend_ops->begin之前输出进入何种状态的suspend，在suspend_ops->end之后输出退出suspend标识。
kworker/u:2-623 [000] .... 164.728912: machine_suspend: state=3-----------------------对应MEM类型的suspend
kworker/u:2-623 [000] .N.. 309.235962: machine_suspend: state=4294967295--------------PWR_EVENT_EXIT的值，也即-1
kworker/u:2-623 [000] .... 310.279083: machine_suspend: state=3
kworker/u:2-623 [000] .N.. 351.880157: machine_suspend: state=4294967295
#define PM_SUSPEND_ON ((__force suspend_state_t) 0)
#define PM_SUSPEND_STANDBY ((__force suspend_state_t) 1)
#define PM_SUSPEND_MEM ((__force suspend_state_t) 3)
#define PM_SUSPEND_MAX ((__force suspend_state_t) 4)
这两个肯定是成对出现，并且他们之间的时间段就是系统睡眠时间。他们之外的就是系统运行的时间。
2.2 trace_cpu_idle_rcuidle
cpuidle的Governor制定cpuidle状态切换策略。
cpuidle锚点位于cpuidle_idle_call中：
int cpuidle_idle_call(void) { ... trace_power_start_rcuidle(POWER_CSTATE, next_state, dev->cpu); trace_cpu_idle_rcuidle(next_state, dev->cpu);-----------------------即将进入cpuidle if (cpuidle_state_is_coupled(dev, drv, next_state)) entered_state = cpuidle_enter_state_coupled(dev, drv, next_state); else entered_state = cpuidle_enter_state(dev, drv, next_state); trace_power_end_rcuidle(dev->cpu); trace_cpu_idle_rcuidle(PWR_EVENT_EXIT, dev->cpu);------------------退出cpuidle ... }
进入的时候记录即将进入的状态，退出的时候也是-1这个特殊值：
<idle>-0 [000] d... 17.718323: cpu_idle: state=0 cpu_id=0 <idle>-0 [000] .... 17.718506: cpu_idle: state=4294967295 cpu_id=0 <idle>-0 [000] d... 17.718506: cpu_idle: state=0 cpu_id=0 <idle>-0 [000] .... 17.719177: cpu_idle: state=4294967295 cpu_id=0
cpuidle有两种状态：OFF深睡和WFI浅睡，这两种需要区分，因为深睡和浅睡对于功耗的影响还是比较大的。
2.3 trace_cpu_frequency
cpufreq和cpuidle之类的trace不一样，cpufreq只需要记录切换频率的点，而不是时间段。
cpufreq的Governor制定侧率，具体的频率点有OPP定义。
void cpufreq_notify_transition(struct cpufreq_freqs *freqs, unsigned int state) { ... switch (state) { case CPUFREQ_PRECHANGE: ... case CPUFREQ_POSTCHANGE: ... trace_cpu_frequency(freqs->new, freqs->cpu);---------------在频率切换后接收消息。 ... } } static int xxx_target(struct cpufreq_policy *policy, unsigned int target_freq, unsigned int relation) { ... for_each_online_cpu(cpu) { freqs.cpu = cpu; cpufreq_notify_transition(&freqs, CPUFREQ_PRECHANGE); } ...----------------------------------------------------------------------------执行频率切换的主题 for_each_online_cpu(cpu) { freqs.cpu = cpu; cpufreq_notify_transition(&freqs, CPUFREQ_POSTCHANGE);-----------------因为频率切换是每个芯片特有的，但是每次切换之后都会发送CPUFREQ_POSTCHANGE。锚点就在此消息处理点中。 } ... }
记录频率切换值和cpu序号：
Line 11743: kworker/u:1-8 [000] .... 61.859894: cpu_frequency: state=624000 cpu_id=0 Line 11824: kworker/u:1-8 [000] .... 309.365387: cpu_frequency: state=312000 cpu_id=0 Line 12173: kworker/u:1-8 [000] .... 310.324127: cpu_frequency: state=624000 cpu_id=0 Line 12191: kworker/u:1-8 [000] .... 950.204895: cpu_frequency: state=312000 cpu_id=0
2.4 trace_irq_handler_entry/trace_irq_handler_exit
中断的锚点放在中断例程前后，可以统计中断执行时间、中断频率等。
void handle_percpu_devid_irq(unsigned int irq, struct irq_desc *desc) { ... trace_irq_handler_entry(irq, action); res = action->handler(irq, dev_id); trace_irq_handler_exit(irq, action, res); ... } irqreturn_t handle_irq_event_percpu(struct irq_desc *desc, struct irqaction *action) { irqreturn_t retval = IRQ_NONE; unsigned int flags = 0, irq = desc->irq_data.irq; do { ... trace_irq_handler_entry(irq, action); res = action->handler(irq, action->dev_id); trace_irq_handler_exit(irq, action, res); ... }
在中断例程之前记录中断号和中断名称，在之后记录中断号和执行结果：
<idle>-0 [000] d.h. 950.700256: irq_handler_entry: irq=68 name=dwc_otg_pcd <idle>-0 [000] d.h. 950.700317: irq_handler_exit: irq=68 ret=handled
基于此，可以统计中断频繁程度、中断例程执行时间，如果中断例程执行时间均方差较大，说明中断例程不太稳定。
2.5 trace_wakeup_source_activate/trace_wakeup_source_deactivate
wakeup source分为两大类：超时wakeup source和手动开关。超时wakeup souce会自动关闭，最多超时时间不准。但是手段lock/unlock的wakeup source，存在不正确关闭的情况。
static void wakeup_source_activate(struct wakeup_source *ws) { ... trace_wakeup_source_activate(ws->name, cec); ... } static void wakeup_source_deactivate(struct wakeup_source *ws) { ... trace_wakeup_source_deactivate(ws->name, cec); ... }
wakeup source和cpuidle、suspend/resume不一样支出在于，不同的wakeup source时间上可能存在重叠。
一个wakeup source的生命周期从wakeup_source_activate开始，到wakeup_source_deactivate结束。
[000] d... 20.269409: wakeup_source_activate: usbcfgmng_lock state=0x28280004--------------锁
...
[000] d... 20.394073: wakeup_source_deactivate: usbcfgmng_lock state=0x28520004------------释放锁
通过分析，可以知道那些wakeup source未能正常释放，那些wakeup source导致系统lock长时间。
2.6 trace_power_domain_target
2.7 trace_clock_enable/trace_clock_disable
2.8 trace_timer_start/trace_timer_cancel/trace_timer_expire_entry/trace_timer_expire_exit
在一个timer起来之后，它的生命存在两种情况：被取消和超时。内核中的timer分为两大类：低精度timer和hrtimer。
hrtimer太过频繁，Trace量会非常大。所以看一下低精度timer。
static inline void debug_activate(struct timer_list *timer, unsigned long expires) { debug_timer_activate(timer); trace_timer_start(timer, expires);--------------------------------启动timer } static inline void debug_deactivate(struct timer_list *timer) { debug_timer_deactivate(timer); trace_timer_cancel(timer);---------------------------------------取消timer } static void call_timer_fn(struct timer_list *timer, void (*fn)(unsigned long), unsigned long data) { ... trace_timer_expire_entry(timer);---------------------------------timer超时函数入口 fn(data); trace_timer_expire_exit(timer);----------------------------------timer超时函数退出 ...
}
关于timer的统计信息，还可以从/proc/timer_stats中读取。默认状态为关闭，使能通过echo 1 > /proc/timer_stats。
3. 抓取Tracepoint数据
抓取Tracepoint需要有针对性，不然数据量太大，导致冗余信息太多，而且buffer空间有限，就会导致buffer不够用。
针对Tracepoint的抓取粒度可以很细：一是针对Tracepoint events进行开关，二是在Tracepoint events内部还可以使用filter。
3.1 抓取Trace设置
#Turn off tracing echo 0 >/sys/kernel/debug/tracing/tracing_on------------------------------先停止Trace抓取 #Disable all traceevents echo 0 >/sys/kernel/debug/tracing/events/enable---------------------------关闭所有Trace events #Clear trace buffer echo > /sys/kernel/debug/tracing/trace------------------------------------清空Trace buffer #Enable power related trace events echo 1 >/sys/kernel/debug/tracing/events/xxx/xxx/enable-------------------打开具体的Trace events，第一层过滤 #Set tracing buffer size echo 4096 >/sys/kernel/debug/tracing/buffer_size_kb-----------------------设置Trace ring buffer大小，可根据情况动态调节 #Move filter function to filter.sh for temp-------------------------------设置每个Trace event的过滤，更细节，需要参考内核代码进行设置。 echo 0 >/sys/kernel/debug/tracing/events/power/wakeup_source_activate/filter
echo 0 >/sys/kernel/debug/tracing/events/power/wakeup_source_deactivate/filter
echo \"((name!=xxx))\" > /sys/kernel/debug/tracing/events/power/wakeup_source_activate/filter
echo \"((name!=xxx))\" > /sys/kernel/debug/tracing/events/power/wakeup_source_deactivate/filter
#Turn on tracing echo 1 >/sys/kernel/debug/tracing/tracing_on-----------------------------开始抓取Trace #Duration of capture trace sleep(50)----------------------------------------------------------------特定时间或采取其他措施 #Disable all traceevents echo 0 >/sys/kernel/debug/tracing/events/enable--------------------------关闭Trace抓取 #Save trace evnts cat /sys/kernel/debug/tracing/trace > /trace.txt-------------------------将Trace内容保存到文件中
还可以通过cat trace_pipe > trace.txt来抓取trace，这种情况抓取trace后会将抓取的内容清除。
就不用担心由于RingBuffer溢出导致的Trace丢失问题。
3.2 Trace event的过滤功能filter
对于Trace events的过滤通过写入字符串给对应events的filter中，如：
echo \"((name!=xxx))\" > /sys/kernel/debug/tracing/events/power/wakeup_source_activate/filter
将会过滤掉名称等于xxx的wakeup_source_activate。name是所谓的Field，这需要根据event不同在代码中找到。
比较符号还可以使用：==、>=、<=、!=、<、>，逻辑符号可以是||、&&。
由于wakeup source和irq两种类型events的trace特别多，看看这两种filter信息。
3.2.1 wakeup source filter
wakeup_source_activate和wakeup_source_deactivate都可以通过name和state进行设置filter。
name: wakeup_source_activate ID: 74 format: ... field:__data_loc char[] name; offset:12; size:4; signed:0; field:u64 state; offset:16; size:8; signed:0; print fmt: "%s state=0x%lx", __get_str(name), (unsigned long)REC->state ID: 73 format: ... field:__data_loc char[] name; offset:12; size:4; signed:0; field:u64 state; offset:16; size:8; signed:0; print fmt: "%s state=0x%lx", __get_str(name), (unsigned long)REC->state
3.2.2 irq filter
name: irq_handler_entry ID: 22 format: ... field:int irq; offset:12; size:4; signed:1; field:__data_loc char[] name; offset:16; size:4; signed:0; print fmt: "irq=%d name=%s", REC->irq, __get_str(name) name: irq_handler_exit ID: 21 format: ... field:int irq; offset:12; size:4; signed:1; field:int ret; offset:16; size:4; signed:1; print fmt: "irq=%d ret=%s", REC->irq, REC->ret ? "handled" : "unhandled"
4. 抓取功耗数据
通过GPIB-USB连接Keisight 66319D，使用PyVISA抓取功耗数据。
Windwos下需要安装《Agilent IO Libraries Suite》，可以到Keisight IO程序库套件下载。
安装好后可以在设备管理器中看到对应的设备，GPIB0::5::INSTR对应GPIB编号0，设备号对应5。
Keisight 66319D使用
对66319D的编程需要参考《User's Guide Agilent Model 66111A ... Mobile Communications DC Source》，重点在《Chapter 7 Programming the DC Source》。
1. Programming the Output
当仪表被上电后，输出是被关闭的，电压输出为0。系统在上电是默认执行了以下命令：
*RST
*CLS
STAT:PRES
*SRE 0
*ESE 0
2. 设置输出电流电压值
VOLT 5---------设置输出1电压为5V
VOLT2 5---------设置输出2电压为5V
CURR <n>-------设置输出1电流为nA
CURR2 <n>-------设置输出2电流为nA
OUTP OFF--------关闭输出
OUTP ON---------打开输出
3. 读取电流电压值
MEAS:VOLT?
MEAS:CURR?--------------------------测试输出1的电压电流值，这个值是一个平均值，仪表内部已经做过运算。他受到采样周期、采样数、运算窗口函数影响。
MEAS:VOLT2?
MEAS:CURR2?-------------------------测试输出2的电压电流值
SENS:SWE:TINT <sample_period>-------采样周期
SENS:SWE:POIN <points>--------------采样数
SENS:SWE:TINT 46.8E-6;POIN 1500-----采样周期和采样数二合一
SENS:WIND: HANN | RECT--------------设置仪表内部测量窗口函数，汉宁窗口或矩形窗口
在仪表上电后有一个默认状态，电压电流的采样率是15.6微秒，窗口扫描尺寸是2048个。15.6X2048即32毫秒左右，加上命令处理需要额外10+毫秒左右，所以实际读取周期45ms左右是正常的。
如何提高读取周期呢？不能简单的通过设置采样周期，降低采样数来是想。
尽量保持最低采样周期，调整采样数来观察数据，如果采样数过低会导致电流负值出现。
实测在采样数为64时，电流比较正常稳定。
具体抓取的在5.4 PyVISA中介绍。
5. 工具基础库
可能遇到的集中类型锚点：
1.电流功耗图形，X轴timeline从0s开始，Y轴是mA数据。其他所有锚点数据X轴timeline严格和电流功耗0s同步。
2.只有一个点时间的cpufreq，绘制成不同高度的阶梯图形。
3.有起止点时间的cpuidle/timer/wakesource/resume-suspend等，绘制成条状。
4.对每个内核行为的功耗进行量化，比如runing多少功耗、cpuidle深睡多少功耗、cpuidle多少功耗、不同cpufreq多少功耗，然后建立模型绘出预期值。和实际功耗图对比，找出哪里异常。
5.1 matplotlib
5.2 csv
CSV即Comma Separated Values，是一种简单的数据存取文件。其使用也很简单。
CSV参考文档中详细介绍了对于CSV文件的读写等操作。
#!/usr/bin/python import csv csv_input = "csv_input.txt" csv_output = "csv_output.csv" csv_input_file = open(csv_input, 'rb') csv_output_file = open(csv_output, 'wb')-------------------创建文件句柄 csv_reader = csv.reader(csv_input_file, delimiter=' ')-----创建读对象 csv_writer = csv.writer(csv_output_file)-------------------创建写对象 csv_writer.writerow(['Name', 'Age'])-----------------------写一行 for i in csv_reader:---------------------------------------遍历读句柄所有航 print i[0], i[1] csv_writer.writerow([i[0], i[1]]) csv_input_file.close() csv_output_file.close()------------------------------------关闭文件句柄
测试程序：https://github.com/arnoldlu/pm-debug/tree/master/test/csv
5.3 Python时间戳以及定时器
在Linux下Python时间可以轻松达到微妙级别，但是在Window上精度只能达到毫秒级别。
time.sleep(duration)
睡眠一定时间，duration为秒数，类型可以为浮点数，所以可以小于1秒。
#!/usr/bin/python import time import datetime import sched import threading sleep_duration = 0.001 sleep_count = 1000 start = datetime.datetime.utcnow() for i in range(sleep_count): time.sleep(sleep_duration) # print i, datetime.datetime.utcnow() end = datetime.datetime.utcnow() print 'Time sleep total=', (end - start).total_seconds(), 'Sleep=', sleep_duration, 'Count=', sleep_count
结果如下：
Time sleep total= 1.090258 Sleep= 0.001 Count= 1000------------睡眠1000次，每次1ms，总共消耗1.09s
sched.scheduler.enter()
使用sched来执行timer功能，在超时函数中再次触发timer，以达到周期性功能。
#!/usr/bin/python import time import datetime import sched schedule = sched.scheduler(time.time, time.sleep) schedule_expires = 0.001 schedule_count = 0 schedule_max = 1000 def schedule_func(timer_start): global schedule_count #now = datetime.datetime.utcnow() #print 'count-', schedule_count, 'duration-', (now - start).total_seconds(), 'expire-', (now - timer_start).total_seconds() schedule_count += 1 if schedule_count < schedule_max: schedule.enter(schedule_expires, 0, schedule_func, (datetime.datetime.utcnow(),)) start = datetime.datetime.utcnow() schedule.enter(schedule_expires, 0, schedule_func, (datetime.datetime.utcnow(),)) schedule.run() end = datetime.datetime.utcnow() print 'Scheduler total=', (end - start).total_seconds(), 'Expire=', schedule_expires, 'Count=', schedule_max
结果如下：
Scheduler total= 1.107005 Expire= 0.001 Count= 1000-----------------------------消耗1.11s
第一个参数是一个整数或者float，代表多少秒后执行这个action任务。
第二个参数priority是优先级，0代表优先级最高，1次之，2次次之…当两个任务是预定在同一个时刻执行时，根据优先级决定谁先执行。
第三个参数就是你要执行的任务，可以简单的理解成你要执行的函数的函数名。
第四个参数是你要传入的这个定时执行的action为函数名的函数的参数，最好是用"()"括号来包起来，包起来肯定是不会出错的。其次，当你只传入一个参数时，用括号包起来后，一定要记住再打上一个逗号。即：schedule.enter(delay, priority, action, (argument1,)) 虽然看起来有有点怪，但一定要这样，否则，会出现错误，比如你不打逗号，你传入一个字符串，它会以为你传入的是一个个字符，且每个字符的地位等于一个参数。总之切记，打上逗号，就安全了。否则会出问题的。 另外如果没有参数要传入，就直接传入空括号即可，即：schedule.enter(delay, priority, action, () )
threading.timer()
#!/usr/bin/python import time import datetime import threading threading_expires = 0.001 threading_count = 0 threading_max = 1000 def threading_func(timer_start): global threading_count #now = datetime.datetime.utcnow() #print 'count-', threading_count, 'duration-', (now - start).total_seconds(), 'expire-', (now - timer_start).total_seconds() threading_count += 1 if threading_count < threading_max: threading.Timer(threading_expires, threading_func, (datetime.datetime.utcnow(),)).start() else: end = datetime.datetime.utcnow() print 'Threading total=', (end -start).total_seconds(), 'Expires=', threading_expires, 'Count=', threading_max start = datetime.datetime.utcnow() threading.Timer(threading_expires, threading_func, (datetime.datetime.utcnow(),)).start()
结果如下：
Threading total= 1.257532 Expires= 0.001 Count= 1000---------------------------共消耗1.26s
Windows下获取超过毫秒精度
#!/usr/bin/python import time,ctypes freq = ctypes.c_longlong(0) ctypes.windll.kernel32.QueryPerformanceFrequency(ctypes.byref(freq)) f=freq.value print f ctypes.windll.kernel32.QueryPerformanceCounter(ctypes.byref(freq)) n1=freq.value print n1 time.sleep(1) ctypes.windll.kernel32.QueryPerformanceCounter(ctypes.byref(freq)) n2=freq.value print n2 print (n2-n1)/(f+0.)
结果如下：
3117382 2422873204863 2422876333399 1.00357800231
参考资料：深入学习python （六） 用sched来定时执行任务
测试程序：https://github.com/arnoldlu/pm-debug/tree/master/test/time_and_timer
5.4 PyVISA
针对测量仪器进行编程比较痛苦，存在各种各样的协议以及通过不同接口和总线（GPIB、USB、RS232）。使用任何一种语言去编程，你必须找到支持仪器和对应总线的合适的库。
为了解决这种问题，VISA应运而生。VISA即Virtual Instrument Software Architecture。VISA已经在主流的操作系统实现，并且不少供应商提供相应的库，部分可以免费下载。
VISA可以被任何能调用DLL库的语言使用，Python理所当然也支持。
安装对应设备提供的驱动程序，可以在设备控制台中看到对应的端口。Agilent示例如下，此时设备和接口都已经接通。
PyVISA安装
使用pip: pip install pyvisa
使用easy_install： easy_install pyvisa
或者下载源码到本地安装： python setup.py install
PyVISA使用
读取66319D数据并且保存到csv文件中。
import visa import time import datetime import numpy import pandas as pd measure_count = 0 measure_count_max = 100 results = pd.DataFrame() temp = {} rm = visa.ResourceManager() res = rm.list_resources() print "Find following resources: ", res print("Opening " + res[-1]) inst = rm.open_resource(res[-1]) # Check if device avaiable measure_start = time.time() inst.query("*IDN?") measure_end = time.time() print 'Duration of IDN query:', str((measure_end-measure_start)*1000), 'ms' #Set the power supply output inst.write("INST P6V") # Select +6V output inst.write("VOLT 4.0") # Set output voltage to 4.0 V inst.write("CURR 2.0") # Set output current to 2.0 A # Power off then power on, delay 1 second for stable inst.write("OUTP OFF") inst.write("OUTP ON") time.sleep(1) measure_start = time.time() inst.query('MEAS:CURR?') measure_end = time.time() print 'Duration of MEAS:CURR? query:', '%.3f' % ((measure_end-measure_start)*1000), 'ms' measure_start = datetime.datetime.utcnow() while True: temp['start'] = (datetime.datetime.utcnow() - measure_start).total_seconds() temp['Imax'] = float(inst.query('MEAS:CURR:MAX?'))*1000 temp['Icur'] = float(inst.query('MEAS:CURR:DC?'))*1000 temp['Imin'] = float(inst.query('MEAS:CURR:MIN?'))*1000 results = results.append(temp, ignore_index=True) measure_count += 1 if measure_count > measure_count_max: break measure_end = datetime.datetime.utcnow() results.to_csv('results.csv') print 'Measurement ending:', (measure_end-measure_start).total_seconds() inst.write("OUTP OFF")
Windows平台结果如下：
Find following resources: (u'GPIB0::5::INSTR',) Opening GPIB0::5::INSTR Duration of IDN query: 6.99996948242 ms-----------------时间太长，只是一个query Duration of MEAS:CURR? query: 45.000 ms-----------------测量一次电流的脚本达到了45ms，太长... Measurement ending: 13.913
参考文档
VISA Specifications：http://www.ivifoundation.org/specifications/default.aspx
PyVISA：https://pypi.python.org/pypi/PyVISA
PyVISA Documentation：https://pyvisa.readthedocs.io/en/stable/
测试程序：https://github.com/arnoldlu/pm-debug/tree/master/test/66319d
5.5 PySerial
由于ADB通信需要通过USB连接，而插入USB会导致系统进入充电模式，仪表电流倒灌。
进而导致电流读数为负值，这种情况无法准确判断功耗情况。
使用串口作为控制台不会导致这种问题，但是串口传输文件是个问题。
import time import serial import serial.tools.list_ports def serial_fd_get(): plist = list(serial.tools.list_ports.comports())---------------------------------------列举当前所有的串口信息 if len(plist) <= 0: print "The Serial port can't find!" else: for i in range(len(plist)):--------------------------------------------------------轮询串口 serialName = list(plist[i])[0] serialDescription = list(plist[i])[1] serialHwid = list(plist[i])[2]-------------------------------------------------列表中共三个信息：串口名，描述信息，硬件ID。其中串口名用来打开串口。 print serialDescription if 'Silicon Labs CP210x USB to UART Bridge' in serialDescription:--------------根据描述信息获取需要的串口 serialFd = serial.Serial(serialName,115200,timeout = 20)-------------------打开串口，获取文件句柄。 print "check which port was really used >",serialFd.name, serialDescription, serialHwid isOpen = serialFd.isOpen()-------------------------------------------------判断能否正确打开 if isOpen: return serialFd return False serialFd = serial_fd_get()------------------------------------------------------------------获取需要的串口句柄，否则轮询 while serialFd == False: print 'Please connect serial cable.' serialFd = serial_fd_get() #Turn off tracing result = serialFd.write('echo 0 >/sys/kernel/debug/tracing/tracing_on\n')------------------写串口 #Disable all traceevents result = serialFd.write('echo 0 >/sys/kernel/debug/tracing/events/enable\n') #Clear trace buffer result = serialFd.write('echo > /sys/kernel/debug/tracing/trace\n') #Turn on tracing result = serialFd.write('echo 1 >/sys/kernel/debug/tracing/tracing_on\n') #Duration of capture trace time.sleep(500) result = serialFd.write('cat /sys/kernel/debug/tracing/buffer_size_kb\n') serialFd.readline()-----------------------------------------------------------------------读串口一行，还有read()/readlinses()等形式。 serialFd.readline() #Disable all traceevents result = serialFd.write('echo 0 >/sys/kernel/debug/tracing/events/enable\n') #Save trace evnts result = serialFd.write('cat /sys/kernel/debug/tracing/trace > /trace.txt\n') time.sleep(5) #This is a MUST BE, or there is no time to finish the executing. serialFd.close()--------------------------------------------------------------------------关文件句柄 serialFd.isOpen()
测试程序：https://github.com/arnoldlu/pm-debug/tree/master/test/PySerial
5.6 Python多线程以及线程同步
测试程序：https://github.com/arnoldlu/pm-debug/tree/master/test/multithread
5.7 PrettyTable
在Python中想简单打印文本，但是有需要有Table格式，很多情况下对齐是个问题。
好在prettytable提供了简单的功能。
from prettytable import PrettyTable col = PrettyTable() col.add_column("City name",["Adelaide","Brisbane","Darwin","Hobart","Sydney","Melbourne","Perth"]) col.add_column("Area", [1295, 5905, 112, 1357, 2058, 1566, 5386]) col.add_column("Population", [1158259, 1857594, 120900, 205556, 4336374, 3806092, 1554769]) col.add_column("Annual Rainfall",[600.5, 1146.4, 1714.7, 619.5, 1214.8, 646.9, 869.4]) print col mix = PrettyTable() mix.field_names = ['City name', 'Area'] mix.add_row(["Adelaide",1295]) mix.add_row(["Brisbane",5905]) mix.add_row(["Darwin", 112]) mix.add_row(["Hobart", 1357]) mix.add_row(["Sydney", 2058]) mix.add_row(["Melbourne", 1566]) mix.add_row(["Perth", 5386]) mix.add_column("Population", [1158259, 1857594, 120900, 205556, 4336374, 3806092, 1554769]) mix.add_column("Annual Rainfall",[600.5, 1146.4, 1714.7, 619.5, 1214.8, 646.9, 869.4]) print mix
结果如下：
+-----------+------+------------+-----------------+ | City name | Area | Population | Annual Rainfall | +-----------+------+------------+-----------------+ | Adelaide | 1295 | 1158259 | 600.5 | | Brisbane | 5905 | 1857594 | 1146.4 | | Darwin | 112 | 120900 | 1714.7 | | Hobart | 1357 | 205556 | 619.5 | | Sydney | 2058 | 4336374 | 1214.8 | | Melbourne | 1566 | 3806092 | 646.9 | | Perth | 5386 | 1554769 | 869.4 | +-----------+------+------------+-----------------+ +-----------+------+------------+-----------------+ | City name | Area | Population | Annual Rainfall | +-----------+------+------------+-----------------+ | Adelaide | 1295 | 1158259 | 600.5 | | Brisbane | 5905 | 1857594 | 1146.4 | | Darwin | 112 | 120900 | 1714.7 | | Hobart | 1357 | 205556 | 619.5 | | Sydney | 2058 | 4336374 | 1214.8 | | Melbourne | 1566 | 3806092 | 646.9 | | Perth | 5386 | 1554769 | 869.4 | +-----------+------+------------+-----------------+
测试程序： https://github.com/arnoldlu/pm-debug/tree/master/test/prettytable
6. 实现机制
6.1 Power、Trace、主线程间同步
Power线程一个锁power_lock，Trace线程一个锁trace_lock。
在主线程启动之后，获取power_lock和trace_lock，这两个锁在Power和Trace线程都执行完毕后才会释放。
所以主线程一直等待，Power和Trace数据获取完毕后才会继续执行下面分析工作。
Power线程启动后需要等待Trace线程开始执行，所以使用power_lock锁住。
Trace线程设置完毕后，抓取Trace之前释放power_lock。此时Power线程和Trace线程同步开始工作。
在得到键盘停止命令后，停止功耗抓取。释放trace_lock，Trace停止抓取。
Trace线程释放主线程锁，执行数据处理。
主要实现：https://github.com/arnoldlu/pm-debug/blob/master/power_analysis.ipynb
6.2 PC时间域和Trace时间域统一
由于Power时间戳和Trace时间戳在两个时间域，他们要同步到一个时间轴上可能存在一点误差。
通过在Trace开始抓取的时候记录trace_measure_start的PC时间，以此为桥梁达到和Power时间的转换。
但是存在一个问题，Trace开始抓取不一定就有数据，可能会隔一段时间。
这时候就需要主动往/sys/kernel/debug/tracing/trace_marker中写入MEASURE_START作为起始标志，在结束的时候写入MEASURE_END作为结束标志。
6.3 Trace数据解析
使用正则表达式来解析Trace每一行文本。主要分为两个步骤：
1.通用部分，解析出进程相关的进程名和进程ID，CPU，flag，时间戳，和消息体。
2.根据每种类型Trace的特性，分情况解析suspend/resume、irq、wakesource、cpuidle、cpufreq。
这两步之后Trace的相关数据就获取到了。
主要实现：https://github.com/arnoldlu/pm-debug/blob/master/analyze_ftrace.py
6.4 数据处理
抓取到功耗数据和Trace数据进行预处理，并将两者的时间域同步之后，数据准备工作就结束了。
下面就是进行数据的分析，分两部分一是输出功耗和内核行为图表，二是输出总结文档。
主要实现：https://github.com/arnoldlu/pm-debug/blob/master/power_analysis.ipynb
6.4.1 输出图表分析
输出的svg图分为5行：
1-是功耗数据曲线图，将系统Running状态覆盖在功耗图上。同时对超出阈值电流一段时间的区域进行高亮，并给出耗电量和平均电流。
2-是中断例程耗时图，同一中断在一行，超出一定时间的中断显示中断名称。
3-是唤醒源耗时图，按唤醒源分行，超出一定时间显示唤醒源名称。
4-是cpuidle耗时图，这两面有两种状态深睡对应紫色区域，浅睡对应黄色区域。
5-是cpu频率变化曲线。
6.4.2 输出总结分析
这里面和上面图表分析内容有部分重复，但是时间不同。
比较重要的两部分是IRQ和Wakesource。这两部分的统计信息对于了解中断和唤醒源的耗时平均值、最大值、最小值、频繁程度、均方差都很有效。
7. 功耗分析
有了上面的图表和总结输出，可以按照下面流程对异常功耗进行分析。
1. 先看功耗图形，红色区域是异常点。然后看此区域都被哪个核的Running状态覆盖，就可以知道是哪个核引起的功耗增加。
2. 确定是哪个核之后，然后在分析细节中断/wakesource等等。是哪个中断唤醒的，保持唤醒多久。这时可以打开更丰富的log显示细节。比如哪个进程、哪个CPU等等。
3. 然后再看看此时的cpuidle和cpufreq等是否正常。
下面看一个由Linux中断唤醒导致的功耗。
1-看出功耗和Running的关系，在Running前功耗已经起来，这是由于软件要滞后于中断唤醒；
2-在运行一段时间之后，功耗就跳变，可以对照cpuidle，此时CPU进入了idle状态。
3-同时CPU频率由624M降到312M。
4-在来到中断一行，可以看出唤醒中断和其他Running下运行的硬中断。
5-两个重要的唤醒源都保持了1s左右，这也是系统保持唤醒超过1s的主要原因。
8. 开发平台Jupyter Notebook
到Anaconda Download下载开发环境，安装好后选择Jupyter Notebook。
8.1 添加扩展功能
pip install jupyter_contrib_nbextensions
安装之后可以在Nbextensions页面进行扩展功能的配置，打开Table of Contents、Exectute Time等功能。
8.2 使用方法
如果修改了库文件，需要Kernel->Restart & Run All。
可以添加目录，像草稿本一样。#是一层，##是二层，以此类推。
File->Download as将文件保存为其他形式。
9. 小结
通过工具化，尽量减少工作量，同时也能避免人操作带来的不确定行。
对功耗异常点的自动分析，将异常点相关行为记录显示，方便发现问题。
基于此，还可以进行扩展，可能优化点:
1. suspend/resume优化流程，找出耗时异常部分。不停进行回归测试，防止某些设备引入长时间suspend、resume函数。
2. 在OPP数目较多时，评估不同Governor优劣。
3. cpuidle问题不太大，主要看是否尽量进入了深睡。
3. irq重点关注长时中断例程、不稳定中断例程。
4. 超时wakeup source重点关注超市误差是否太大，非超时wakeup source是否正确释放。
