内核版本：v3.4.xxx
一、前言
内核提供了方便查看当前系统TickDevice、活动的Timer列表以及Timer使用的统计信息。
内核分别用两个节点来表示TimerList和Timer统计信息。
一个是/proc/timer_list，打印per_cpu的hrtimer_bases信息以及基于此的timer列表，包括三种时钟MONOTONIC/REALTIME/BOOTTIME；以及Broadcast Tick Device和Per CPU Tick Device信息。
另一个是/proc/timer_stats，需要echo 1 > /proc/timer_stats打开，echo 0 /proc/timer_stats关闭。cat /proc/timer_stats可以获取统计信息。
二、背景介绍
Per CPU TickDevice是维护当前CPU Tick和hrtimer的基础，只有工作在OneShot模式下才能实现hrtimer。在CPU进入cpuidle后，Per CPU TickDevice可能会被关闭，这时候可以打开Broadcast Tick作为唤醒源。超时后，就会将系统从cpuidle退出，进入正常工作模式打开Per CPU TickDevice。
hrtimer有三种时钟基准，这三种时钟基准对应不同的时间获取函数，但主要是基于TimeKeeping的统计。
三、认识timer_list
kernel/time/timer_list.c中init_timer_list_procfs创建/proc/timer_list节点。
|
static int timer_list_show(struct seq_file *m, void *v)
{
u64 now = ktime_to_ns(ktime_get());
int cpu;
SEQ_printf(m, "Timer List Version: v0.6\n");------------------------------------------------------------------(1)
SEQ_printf(m, "HRTIMER_MAX_CLOCK_BASES: %d\n", HRTIMER_MAX_CLOCK_BASES);
SEQ_printf(m, "now at %Ld nsecs\n", (unsigned long long)now);
for_each_online_cpu(cpu)----------------------------------------------------------------------------------------(2)
print_cpu(m, cpu, now);
SEQ_printf(m, "\n");
timer_list_show_tickdevices(m);--------------------------------------------------------------------------------(3)
return 0;
}
|
(1)打印概况信息，hrtimer基准时钟个数和系统MONOTONIC时间。
(2)这里是per_cpu信息，按照hrtimer_cpu_base->hrtimer_clock_base->hrtimer层级关系打印。
(3)打印Broadcast TickDevice和per_cpu的TickDevice设备信息。
下面根据一个示例来分析：
|
Timer List Version: v0.6
HRTIMER_MAX_CLOCK_BASES: 3
now at 86212951044093 nsecs
cpu: 0-----------------------print_cpuCPU0的信息如下，从clock0到clock2
clock 0:---------------------clock0作为MONOTONIC使用ktime_get获取当前时间，是timerkeeper的xtime和wall_to_monotonic之和。
.base: c0531950
.index: 0
.resolution: 1 nsecs
.get_time: ktime_get
.offset: 0 nsecs------------和MONOTONIC相比的offset。
active timers:--------------print_active_timers打印所有的hrtimer，按照时间排列，timerqueue_iterate_next读取rbtree的next。
--依次是：序列号、hrtimer、timer状态、hrtimer超时函数、进程名/进程号
--超时绝对时间和相对时间。
#0: <c0532620>, tick_sched_timer, S:01, hrtimer_start_range_ns, swapper/0
# expires at 86212955000000-86212955000000 nsecs [in 3955907 to 3955907 nsecs]
#1: <c11d1f20>, hrtimer_wakeup, S:01, hrtimer_start_range_ns, xxx_log_agent/1326
# expires at 86212957402735-86212957452735 nsecs [in 6358642 to 6408642 nsecs]
#2: <c1289ab8>, hrtimer_wakeup, S:01, hrtimer_start_range_ns, xxx_ipsec_proxy/1349
# expires at 86213073541650-86213076541650 nsecs [in 122497557 to 125497557 nsecs]
#3: <c11d3f20>, hrtimer_wakeup, S:01, hrtimer_start_range_ns, xxx_log_agent/1327
# expires at 86213291925439-86213291975439 nsecs [in 340881346 to 340931346 nsecs]
#4: <c105df20>, hrtimer_wakeup, S:01, hrtimer_start_range_ns, xxx_log_agent/1324
# expires at 86213768121728-86213768171728 nsecs [in 817077635 to 817127635 nsecs]
#5: <c108bf20>, hrtimer_wakeup, S:01, hrtimer_start_range_ns, xxx_log_agent/1325
# expires at 86213768152245-86213768202245 nsecs [in 817108152 to 817158152 nsecs]
#6: <c104fab8>, hrtimer_wakeup, S:01, hrtimer_start_range_ns, at_ctl/785
# expires at 86214382959375-86214387959375 nsecs [in 1431915282 to 1436915282 nsecs]
#7: <c12bbf20>, hrtimer_wakeup, S:01, hrtimer_start_range_ns, dm_ci/1365
# expires at 86248421289453-86248421339453 nsecs [in 35470245360 to 35470295360 nsecs]
#8: <c11d7ab8>, hrtimer_wakeup, S:01, hrtimer_start_range_ns, udhcpd/1147
# expires at 86409238207327-86409338207327 nsecs [in 196287163234 to 196387163234 nsecs]
#9: <c1aadd90>, it_real_fn, S:01, hrtimer_start, SoftTimerLoop/782
# expires at 86421323022854-86421323022854 nsecs [in 208371978761 to 208371978761 nsecs]
#10: <c11dff20>, hrtimer_wakeup, S:01, hrtimer_start_range_ns, netmonitor/1313
# expires at 86421323999417-86421324049417 nsecs [in 208372955324 to 208373005324 nsecs]
clock 1:
.base: c0531988
.index: 1
.resolution: 1 nsecs
.get_time: ktime_get_real
.offset: 946759810014430770 nsecs
active timers:
#0: <c0563760>, alarmtimer_fired, S:01, hrtimer_start, sample/1354
# expires at 946846022969655783-946846022969655783 nsecs [in 946759810018611690 to 946759810018611690 nsecs]
clock 2:
.base: c05319c0
.index: 2
.resolution: 1 nsecs
.get_time: ktime_get_boottime
.offset: 706858435 nsecs
active timers:
-------------------------------------------------------------------hrtimer_cpu_base部分，参照结构体解释----------------------------------------------------------------------
.expires_next : 86212955000000 nsecs---------CPU层次看hrtimer信息，可以在上面找到对应的最近一次expires
.hres_active : 1
.nr_events : 4648009
.nr_retries : 4467
.nr_hangs : 0
.max_hang_time : 0 nsecs
---------------------------------------------------------------------tick_sched部分，参照结构体解释-----------------------------------------------------------------------------
.nohz_mode : 2--------------------------------------nohz_mode对应NOHZ_MODE_INACTIVE(0)、NOHZ_MODE_LOWRES(1)、NOHZ_MODE_HIGHRES(2)。
.idle_tick : 86212945000000 nsecs
.tick_stopped : 0
.idle_jiffies : 17182588
.idle_calls : 4632242
.idle_sleeps : 4573348
.idle_entrytime : 86212940790186 nsecs
.idle_waketime : 86212940790186 nsecs
.idle_exittime : 86212940790186 nsecs
.idle_sleeptime : 84593571589272 nsecs
.iowait_sleeptime: 0 nsecs
.last_jiffies : 17182588
.next_jiffies : 17182604
.idle_expires : 86213020000000 nsecs
jiffies: 17182590
Tick Device: mode: 1-----------------------Broadcast TickDevice
Broadcast device
Clock Event Device: <NULL>
tick_broadcast_mask: 00000000
tick_broadcast_oneshot_mask: 00000000
Tick Device: mode: 1---------------------per_cpu TickDevice，详细信息参照clock_event_device结构体解释。
Per CPU device: 0
Clock Event Device: xxx_ap_timer0
max_delta_ns: 660764185443
min_delta_ns: 15385
mult: 13958644
shift: 32
mode: 3
next_event: 86212955000000 nsecs
set_next_event: xxx_timer_set_next_event
set_mode: xxx_timer_set_mode
event_handler: hrtimer_interrupt
retries: 165992
|
四、认识timer_stats
kernel/time/timer_stats.c中init_tstas_procfs创建了/proc/timer_stats节点。统计细心
在每次hrtimer超时函数中都会进行统计，必须打开CONFIG_TIMER_STATS才有效。
| __hrtimer_start_range_ns-->raise_softirq_irqoff-->HRTIMER_SOFTIRQ-->run_hrtimer_softirq-->hrtimer_interrupt-->__run_hrtimer-->timer_stats_account_hrtimer |
timer_stats_account_hrtimer是执行统计信息的主体，这里面有一个timer_stats_active开关。是通过echo [0|1] > /proc/timer_stats进行开关。
|
void timer_stats_update_stats(void *timer, pid_t pid, void *startf,
void *timerf, char *comm,
unsigned int timer_flag)
{
/*
* It doesn't matter which lock we take:
*/
raw_spinlock_t *lock;
struct entry *entry, input;
unsigned long flags;
if (likely(!timer_stats_active))----------------------------------------是否打开开关
return;
lock = &per_cpu(tstats_lookup_lock, raw_smp_processor_id());
input.timer = timer;---------------------------------------------------填充entry结构体
input.start_func = startf;
input.expire_func = timerf;
input.pid = pid;
input.timer_flag = timer_flag;
raw_spin_lock_irqsave(lock, flags);
if (!timer_stats_active)
goto out_unlock;
entry = tstat_lookup(&input, comm);-------------------------------在tstat_hash_table中查找input，找到count递增；没找到新增一个entry插入hash表。
if (likely(entry))
entry->count++;
else
atomic_inc(&overflow_count);
out_unlock:
raw_spin_unlock_irqrestore(lock, flags);
}
|
显示的地方在tstats_show，所有的统计信息存放在static struct entry entries[MAX_ENTRIES]结构体数组中，当前entry数目通过nr_entries来记录。
|
static int tstats_show(struct seq_file *m, void *v)
{
struct timespec period;
struct entry *entry;
unsigned long ms;
long events = 0;
ktime_t time;
int i;
mutex_lock(&show_mutex);
/*
* If still active then calculate up to now:
*/
if (timer_stats_active)
time_stop = ktime_get();
time = ktime_sub(time_stop, time_start);
period = ktime_to_timespec(time);
ms = period.tv_nsec / 1000000;
seq_puts(m, "Timer Stats Version: v0.2\n");
seq_printf(m, "Sample period: %ld.%03ld s\n", period.tv_sec, ms);
if (atomic_read(&overflow_count))
seq_printf(m, "Overflow: %d entries\n",
atomic_read(&overflow_count));
for (i = 0; i < nr_entries; i++) {----------------------遍历entries数组，数组内容在每次hrtimer中断处理中进行更新。
entry = entries + i;
if (entry->timer_flag & TIMER_STATS_FLAG_DEFERRABLE) {
seq_printf(m, "%4luD, %5d %-16s ",
entry->count, entry->pid, entry->comm);
} else {
seq_printf(m, " %4lu, %5d %-16s ",
entry->count, entry->pid, entry->comm);
}
print_name_offset(m, (unsigned long)entry->start_func);
seq_puts(m, " (");
print_name_offset(m, (unsigned long)entry->expire_func);
seq_puts(m, ")\n");
events += entry->count;
}
ms += period.tv_sec * 1000;
if (!ms)
ms = 1;
if (events && period.tv_sec)
seq_printf(m, "%ld total events, %ld.%03ld events/sec\n",
events, events * 1000 / ms,
(events * 1000000 / ms) % 1000);
else
seq_printf(m, "%ld total events\n", events);
mutex_unlock(&show_mutex);
return 0;
}
|
一个实例分析：
|
Timer Stats Version: v0.2
Sample period: 42.997 s
--依次是：timer count、进程号、进程名称、超时函数、启动timer函数
2112, 1300 xxx_log_agent hrtimer_start_range_ns (hrtimer_wakeup)
43, 1299 xxx_log_agent hrtimer_start_range_ns (hrtimer_wakeup)
43, 1298 xxx_log_agent hrtimer_start_range_ns (hrtimer_wakeup)
43, 1301 xxx_log_agent hrtimer_start_range_ns (hrtimer_wakeup)
5, 1881 sample hrtimer_start (alarmtimer_fired)
116, 0 swapper hrtimer_start_range_ns (tick_sched_timer)
14, 1355 xxx_ipsec_proxy hrtimer_start_range_ns (hrtimer_wakeup)
28, 0 swapper hrtimer_start (tick_sched_timer)
17D, 0 swapper cpufreq_interactive_timer_resched.constprop.8 (cpufreq_interactive_timer)
8, 794 at_ctl hrtimer_start_range_ns (hrtimer_wakeup)
6, 0 swapper run_timer_softirq (sync_supers_timer_fn)
4, 0 swapper DWC_TIMER_SCHEDULE (timer_callback)
4, 0 swapper DWC_TIMER_SCHEDULE (timer_callback)
4, 0 swapper DWC_TIMER_SCHEDULE (timer_callback)
4, 0 swapper br_hello_timer_expired (br_hello_timer_expired)
3, 613 zx_wdt_thread msleep (process_timeout)
2D, 4 kworker/0:0 neigh_periodic_work (delayed_work_timer_fn)
2D, 4 kworker/0:0 neigh_periodic_work (delayed_work_timer_fn)
2, 1366 adbd DWC_TIMER_SCHEDULE (timer_callback)
1, 0 swapper igmp6_group_queried (igmp6_timer_handler)
1, 1371 dm_ci hrtimer_start_range_ns (hrtimer_wakeup)
1, 0 swapper igmp6_group_queried (igmp6_timer_handler)
1, 0 swapper igmp6_group_queried (igmp6_timer_handler)
2464 total events, 57.306 events/sec
|
五、使用
1.通过timer_stats可以知道系统的timer使用程度，一定程度上反映了进程的活跃状态。
2.timer_list可以知道系统TickDevice相关设备信息。
3.还可以知道timer状态，以及即将发生的Timer。
4.系统相关信息尤其是tick_sched(系统调度jiffies、idle、iowait等)和hrtimer_cpu_base(retries、hang)部分。
