Linux 内核 add_timer 在分辨率为一瞬间的可靠性? [英] Reliability of Linux kernel add_timer at resolution of one jiffy?

查看:9
本文介绍了Linux 内核 add_timer 在分辨率为一瞬间的可靠性?的处理方法,对大家解决问题具有一定的参考价值,需要的朋友们下面随着小编来一起学习吧!

问题描述

在下面给出的代码中,有一个简单的 Linux 内核模块(驱动程序),它使用 add_timer 以 1 jiffy 的分辨率重复调用一个函数 10 次(即定时器被调度到在 jiffies + 1 处开火).使用 bash 脚本 rerun.sh,然后我从 syslog 的打印输出中获取时间戳,并使用 gnuplot 将它们可视化.

在大多数情况下,我会得到这样的 syslog 输出:

[ 7103.055787] 初始化 testjiffy: 0 ;赫兹:250;1/HZ(毫秒):4[7103.056044]testjiffy_timer_function:runco​​unt 1[7103.060045]testjiffy_timer_function:runco​​unt 2[7103.064052]testjiffy_timer_function:runco​​unt 3[7103.068050]testjiffy_timer_function:runco​​unt 4[7103.072053]testjiffy_timer_function:runco​​unt 5[7103.076036]testjiffy_timer_function:runco​​unt 6[7103.080044]testjiffy_timer_function:runco​​unt 7[7103.084044]testjiffy_timer_function:runco​​unt 8[7103.088060]testjiffy_timer_function:runco​​unt 9[7103.092059]testjiffy_timer_function:runco​​unt 10[7104.095429]退出testjiffy

... 产生的时间序列和 delta 直方图如下所示:

本质上,这就是我期望从代码中获得的时间质量.

然而 - 每隔一段时间,我就会得到一个像:

[ 7121.377507] 初始化 testjiffy: 0 ;赫兹:250;1/HZ(毫秒):4[7121.380049]testjiffy_timer_function:runco​​unt 1[7121.384062]testjiffy_timer_function:runco​​unt 2[7121.392053]testjiffy_timer_function:runco​​unt 3[7121.396055]testjiffy_timer_function:runco​​unt 4[7121.400068]testjiffy_timer_function:runco​​unt 5[7121.404085]testjiffy_timer_function:runco​​unt 6[7121.408084]testjiffy_timer_function:runco​​unt 7[7121.412072]testjiffy_timer_function:runco​​unt 8[7121.416083]testjiffy_timer_function:runco​​unt 9[7121.420066]testjiffy_timer_function:runco​​unt 10[7122.417325]退出testjiffy

... 渲染结果如下:

...我就像:WHOOOOOAAAAAA...等一下..." - 没有从序列中掉下一个脉冲吗?意味着 add_timer 错过一个时隙,然后在下一个 4 ms 时隙中启动函数?

有趣的是,在运行这些测试时,我只有一个终端、Web 浏览器和一个已启动的文本编辑器——所以我真的看不到任何正在运行的东西,这可能会占用操作系统/内核;因此,我真的看不出有什么原因为什么内核会造成如此大的失误(整个瞬间).当我阅读有关 Linux 内核时序的信息时,例如"所有计时器中最简单和最不准确的……是计时器 API",我将最不准确"读作:不要期望 恰好 4 ms 周期"(根据此示例)-我不知道,我对(第一)直方图中显示的方差;但没想到会错过一整期!?

所以我的问题是:

  • 这是 add_timer 在此分辨率下的预期行为吗(偶尔会错过一段时间)?
  • 如果是这样,是否有办法强制"add_timer 在每个 4ms 时隙触发该函数,如该平台上的 jiffy 所指定的那样?
  • 我是否有可能得到一个错误"的时间戳 - 例如时间戳反映实际打印"到系统日志的时间,而不是函数实际触发的时间?
  • 请注意,我不是在寻找低于 jiffy(在本例中为 4 毫秒)的周期分辨率;当代码正常工作时,我也不希望减少增量方差.所以在我看来,我没有高分辨率计时器"的需求,也没有硬实时"的需求——我只是想让 add_timer 可靠地触发.在这个平台上这是否可能,而无需求助于内核的特殊实时"配置?

额外问题:在下面的 rerun.sh 中,您会注意到两个 sleep 标有 MUSTHAVE;如果它们中的任何一个被遗漏/注释,操作系统/内核冻结,并且需要重启.我不明白为什么 - 在 insmod 之后从 bash 运行 rmmod 真的有可能这么快,它会与正常进程冲突吗?模块加载/卸载?

<小时>

平台信息:

$ cat/proc/cpuinfo |grep "处理器|型号名称|MHz|内核"处理器:0 #(1 相同)型号名称:Intel(R) Atom(TM) CPU N450 @ 1.66GHzCPU 兆赫:1000.000CPU核心:1$ echo $(cat/etc/issue ; uname -a)Ubuntu 11.04 
 l Linux mypc 2.6.38-16-generic #67-Ubuntu SMP Thu Sep 6 18:00:43 UTC 2012 i686 i686 i386 GNU/Linux$ echo $(lsb_release -a 2>/dev/null | tr '
' ' ')发行商 ID:Ubuntu 描述:Ubuntu 11.04 版本:11.04 代号:natty

代码:

$ cd/tmp/testjiffy$lsMakefile rerun.sh testjiffy.c

Makefile:

obj-m += testjiffy.o全部:make -C/lib/modules/$(shell uname -r)/build M=$(PWD) 模块干净的:make -C/lib/modules/$(shell uname -r)/build M=$(PWD) clean

testjiffy.c:

/** [http://www.tldp.org/LDP/lkmpg/2.6/html/lkmpg.html#AEN189 Linux 内核模块编程指南]*/#include /* 所有模块都需要 */#include /* KERN_INFO 需要 */#include /* 宏需要 */#include #include #define MAXRUNS 10静态易失性 int 运行计数 = 0;静态结构定时器列表 my_timer;static void testjiffy_timer_function(无符号长数据){int tdelay = 100;运行计数++;如果(运行计数 == 5){而 (tdelay > 0) { tdelay--;}//小延迟}打印(KERN_INFO" %s: 运行计数 %d 
",__func__,运行次数);如果(运行计数 

rerun.sh:

#!/usr/bin/env bash设置 -x清洁制作# 先清空系统日志须藤 bash -c 'echo "0" >/var/log/syslog'睡眠 1 # 必须 01!# 重新加载内核模块/驱动程序须藤insmod ./testjiffy.ko睡眠 1 # 必须 02!须藤 rmmod testjiffy设置 +x# 复制 &进程系统日志最大值=0;对于 _testjiffy_*.syslog 中的 ix;做aa=${ix#_testjiffy_};ab=${aa%.syslog} ;案例 $ab 在*[!0-9]*) ab=0;;# 如果获得非数字则重置;别的*) ab=$(echo $ab | bc);;# 删除前导零(否则为八进制)esac如果 (( $ab > $max )) ;然后最大值=$((ab));fi;完毕;newm=$( printf "%05d" $(($max+1)));PLPROC='chomp $_;如果 (!$p) {$p=0;};if (!$f) {$f=$_;} else {$a=$_-$f;$d=$a-$p;打印 "$a $d
" ;$p=$a;};'设置 -xgrep "testjiffy"/var/log/syslog |cut -d' ' -f7- >_testjiffy_${newm}.sysloggreptestjiffy_timer_function"_testjiffy_${newm}.syslog |sed 's/[(.*)].*/1/' |perl -ne "$PLPROC" >_testjiffy_${newm}.dat设置 +x猫 >_testjiffy_${newm}.gp <<EOF设置终端 pngcairo 字体 'Arial,10' 大小 900,500设置输出 '_testjiffy_${newm}.png'设置样式 line 1 linetype 1 linewidth 3 pointtype 3 linecolor rgb "red"设置多图布局 1,2 标题_testjiffy_${newm}.syslog"设置 xtics 旋转 -45设置标题时间位置"设置 yrange [0:1.5]设置偏移图 50e-3, 1e-3, 0, 0绘制 '_testjiffy_${newm}.dat' using 1:(1.0):xtic(gprintf("%.3se%S",$1)) notitle with points ls 1, '_testjiffy_${newm}.dat' using 1:(1.0) 脉冲 ls 1binwidth=0.05e-3设置 boxwidth binwidthbin(x,width)=width*floor(x/width) + width/2.0设置标题Delta diff 直方图"设置样式填充实心 0.5设置自动缩放 xy设置偏移图 0.1e-3, 0.1e-3, 0.1, 0.1使用 (bin($2,binwidth)):(1.0) 平滑频率与框 ls 1 绘制 '_testjiffy_${newm}.dat'取消设置多图EOF设置 -x;gnuplot _testjiffy_${newm}.gp ;设置 +x

<小时>

this 激发@granquet 的评论,我尝试使用 dd/proc/schedstat/proc/sched_debug 获取调度程序统计信息通过call_usermodehelper;请注意,这在大多数情况下会跳过"(即,由于函数的第 7、6 或 X 次运行而导致的文件将丢失);但我设法获得了两次完整的运行,并将它们发布在 https://gist.github.com/anonymous/5709699(因为我注意到在 SO 上 gist 可能比 pastebin 更受欢迎),因为输出有点大;*_11* 文件记录了一个正确的运行,*_17* 文件记录了一个带有drop"的运行.

注意我也切换到模块中的mod_timer_pinned,它没有多大帮助(使用这个函数的模块获取gist日志).这些是 testjiffy.c 中的变化:

#include //用户模式助手 API...char fcmd[] = "of=/tmp/testjiffy_sched00";char *dd1argv[] = { "/bin/dd", "if=/proc/schedstat", "oflag=append", "conv=notrunc", &fcmd[0], NULL };char *dd2argv[] = { "/bin/dd", "if=/proc/sched_debug", "oflag=append", "conv=notrunc", &fcmd[0], NULL };静态字符 *envp[] = {"家=/","TERM=linux","PATH=/sbin:/bin:/usr/sbin:/usr/bin", NULL };static void testjiffy_timer_function(无符号长数据){int tdelay = 100;无符号长tjnow;运行计数++;如果(运行计数 == 5){而 (tdelay > 0) { tdelay--;}//小延迟}打印(KERN_INFO" %s: 运行计数 %d 
",__func__,运行次数);如果(运行计数  %lu/%lu
",my_timer.expires, tjnow, my_timer.expires-tjnow, jiffies);sprintf(fcmd, "of=/tmp/testjiffy_sched%02d", runco​​unt);call_usermodehelper(dd1argv[0],dd1argv,envp,UMH_NO_WAIT);call_usermodehelper(dd2argv[0],dd2argv,envp,UMH_NO_WAIT);}}

... 而这在 rerun.sh 中:

<代码>...设置 +x对于/tmp/testjiffy_sched* 中的 ix;做回声 $ix |tee -a _testjiffy_${newm}.sched猫 $ix >>_testjiffy_${newm}.sched完毕设置 -x ;须藤 rm/tmp/testjiffy_sched* ;设置 +x猫 >_testjiffy_${newm}.gp <<EOF...

<小时>

我将使用这篇文章进行详细回复.

@CL.:非常感谢您的回答.很高兴它确认您的计时器函数可能会在稍后的瞬间被调用";通过记录 jiffies,我也意识到定时器函数会在以后被调用——除此之外,它本身并没有任何错误".

很高兴知道时间戳;我想知道是否有可能:定时器函数在正确的时间命中,但内核抢占内核日志服务(我相信它是 klogd),所以我得到一个延迟的时间戳?然而,我正在尝试创建一个循环"(或者更确切地说,周期性)定时器函数来写入硬件,我首先注意到这个下降"是因为意识到 PC 不会以特定的时间间隔在 USB 总线上写入数据;鉴于时间戳证实了这种行为,这可能不是这里的问题(我猜).

我修改了计时器函数,因此它相对于上一个计时器的预定时间 (my_timer.expires) 触发 - 再次通过 mod_timer_pinned 而不是 add_timer:

static void testjiffy_timer_function(unsigned long data){int tdelay = 100;无符号长tjlast;无符号长tjnow;运行计数++;如果(运行计数 == 5){而 (tdelay > 0) { tdelay--;}//小延迟}打印(KERN_INFO" %s: 运行计数 %d 
",__func__,运行次数);如果(运行计数  %lu/%lu 最后: %lu
",my_timer.expires, tjnow, my_timer.expires-tjnow, jiffies, tjlast);}}

...在前几次尝试中,它的效果无可挑剔 - 然而,最终,我明白了:

[13389.775508] 初始化 testjiffy: 0 ;赫兹:250;1/HZ(毫秒):4[13389.776051] testjiffy_timer_function: runco​​unt 1[13389.776063] testjiffy 过期:3272445 - jiffies 3272444 =>1/3272444 最后一个:3272444[13389.780053] testjiffy_timer_function: runco​​unt 2[13389.780068] testjiffy 过期:3272446 - jiffies 3272445 =>1/3272445 最后一个:3272445[13389.788054] testjiffy_timer_function: runco​​unt 3[13389.788073] testjiffy 过期:3272447 - jiffies 3272447 =>0/3272447 最后一个:3272446[13389.788090] testjiffy_timer_function: runco​​unt 4[13389.788096] testjiffy 过期:3272448 - jiffies 3272447 =>1/3272447 最后一个:3272447[13389.792070] testjiffy_timer_function: runco​​unt 5[13389.792091] testjiffy 过期:3272449 - jiffies 3272448 =>1/3272448 最后一个:3272448[13389.796044] testjiffy_timer_function: runco​​unt 6[13389.796062] testjiffy 过期:3272450 - jiffies 3272449 =>1/3272449 最后一个:3272449[13389.800053] testjiffy_timer_function: runco​​unt 7[13389.800063] testjiffy 过期:3272451 - jiffies 3272450 =>1/3272450 最后一个:3272450[13389.804056] testjiffy_timer_function: runco​​unt 8[13389.804072] testjiffy 过期:3272452 - jiffies 3272451 =>1/3272451 最后一个:3272451[13389.808045] testjiffy_timer_function: runco​​unt 9[13389.808057] testjiffy 过期:3272453 - jiffies 3272452 =>1/3272452 最后一个:3272452[13389.812054] testjiffy_timer_function: runco​​unt 10[13390.815415]退出testjiffy

...呈现如下:

...所以,基本上我在+8ms 时隙(应该是@3272446 jiffies)有一个延迟/下降",然后在+12ms 时隙运行两个 函数(这将是@ 3272447 jiffies);因为它,你甚至可以看到情节上的标签更粗".这更好,因为丢弃"序列现在与适当的非丢弃序列同步(正如您所说:为了避免一个延迟的定时器函数改变所有后续定时器调用") - 但是,我仍然错过一个节拍;并且由于我必须在每次节拍时将字节写入硬件,因此我保持持续、恒定的传输速率,不幸的是,这对我没有多大帮助.

至于另一个建议,使用十个计时器" - 因为我的最终目标(使用周期性低分辨率计时器功能写入硬件);我一开始认为它不适用 - 但如果没有其他可能(除了做一些特殊的实时内核准备),那么我肯定会尝试一个方案,我有 10 个(或 N 个)定时器(可能存储在一个数组),它们会一个接一个地定期触发.

<小时>

只添加剩余的相关评论:

<块引用>

USB 传输要么提前安排(等时),要么没有时间保证(异步).如果您的设备不使用同步传输,则它的设计严重错误.– CL.6 月 5 日 10:47

<块引用>

感谢您的评论,@CL.- ......提前安排(等时)......"消除了我的困惑.我(最终)的目标是 FT232,它只有 BULK 模式 - 只要每个定时器命中的字节数很低,我实际上可以使用 add_timer 在流"数据中欺骗"我的方式;然而,当我传输接近消耗带宽的字节数时,这些失火"开始变得明显下降.所以我有兴趣测试它的极限,为此我需要一个可靠的重复计时器"功能 - 还有什么我可以尝试拥有一个可靠的计时器"的吗?– sdaau 6 月 5 日 12:27

<块引用>

@sdaau 批量传输不适合流式传输.您无法通过使用另一种软件计时器来修复硬件协议中的缺陷.– CL.6 月 5 日 13:50

...以及我对@CL 的回应.:我知道我无法修复缺点;我对观察这些缺点更感兴趣 - 例如,如果内核函数进行定期 USB 写入,我可以观察示波器/分析器上的信号,并希望看到批量模式在什么意义上不合适.但首先,我必须相信该功能可以(至少在某种程度上)以周期性速率可靠地重复(即生成"时钟/滴答声)-直到现在我才意识到我不能真正相信add_timer 以 jiffies 分辨率(因为它能够相对容易地跳过整个周期).然而,从这个意义上说,转向 Linux 的高分辨率计时器 (hrtimer) 似乎确实给了我一个可靠的周期性函数 - 所以我想这解决了我的问题(发布在我的 :您的模块有问题:您必须确保在卸载模块之前计​​时器未挂起",已修复(在 hrtimer 的上下文中).This seemingly answers my bonus question, as it obviates the need for either of the "MUSTHAVE" sleeps in the rerun.sh script.However, note that as 200 loops @ 4 ms take 0.8 s - the sleep between insmod and rmmod is needed if we want a full 200 tick capture (otherwise, on my machine, I get only some 7 ticks captured).

Well, hope I got this right now (at least most if it) - if not, corrections are welcome :)

testjiffy(-hr).c

#include <linux/module.h>  /* Needed by all modules */#include <linux/kernel.h>  /* Needed for KERN_INFO */#include <linux/init.h>    /* Needed for the macros */#include <linux/jiffies.h>#include <linux/time.h>#define MAXRUNS 200#include <linux/hrtimer.h>static volatile int runcount = 0;//~ static struct timer_list my_timer;static unsigned long period_ms;static unsigned long period_ns;static ktime_t ktime_period_ns;static struct hrtimer my_hrtimer;//~ static void testjiffy_timer_function(unsigned long data)static enum hrtimer_restart testjiffy_timer_function(struct hrtimer *timer){int tdelay = 100;unsigned long tjnow;ktime_t kt_now;int ret_overrun;runcount++;if (runcount == 5) {while (tdelay > 0) { tdelay--; }//small delay}printk(KERN_INFO" %s: runcount %d 
",__func__, runcount);if (runcount < MAXRUNS) {tjnow = jiffies;kt_now = hrtimer_cb_get_time(&my_hrtimer);ret_overrun = hrtimer_forward(&my_hrtimer, kt_now, ktime_period_ns);printk(KERN_INFO" testjiffy jiffies %lu ; ret: %d ; ktnsec: %lld 
",tjnow, ret_overrun, ktime_to_ns(kt_now));return HRTIMER_RESTART;}else return HRTIMER_NORESTART;}static int __init testjiffy_init(void){struct timespec tp_hr_res;period_ms = 1000/HZ;hrtimer_get_res(CLOCK_MONOTONIC, &tp_hr_res);printk(KERN_INFO"Init testjiffy: %d ; HZ: %d ; 1/HZ (ms): %ld ; hrres: %lld.%.9ld
",runcount,      HZ,        period_ms, (long long)tp_hr_res.tv_sec, tp_hr_res.tv_nsec );hrtimer_init(&my_hrtimer, CLOCK_MONOTONIC, HRTIMER_MODE_REL);my_hrtimer.function = &testjiffy_timer_function;period_ns = period_ms*( (unsigned long)1E6L );ktime_period_ns = ktime_set(0,period_ns);hrtimer_start(&my_hrtimer, ktime_period_ns, HRTIMER_MODE_REL);返回0;}static void __exit testjiffy_exit(void){int ret_cancel = 0;while( hrtimer_callback_running(&my_hrtimer) ) {ret_cancel++;}if (ret_cancel != 0) {printk(KERN_INFO " testjiffy Waited for hrtimer callback to finish (%d)
", ret_cancel);}if (hrtimer_active(&my_hrtimer) != 0) {ret_cancel = hrtimer_cancel(&my_hrtimer);printk(KERN_INFO " testjiffy active hrtimer cancelled: %d (%d)
", ret_cancel, runcount);}if (hrtimer_is_queued(&my_hrtimer) != 0) {ret_cancel = hrtimer_cancel(&my_hrtimer);printk(KERN_INFO " testjiffy queued hrtimer cancelled: %d (%d)
", ret_cancel, runcount);}printk(KERN_INFO "Exit testjiffy
");}module_init(testjiffy_init);module_exit(testjiffy_exit);MODULE_LICENSE("GPL");

In the code given below, there is a simple Linux kernel module (driver) which calls a function repeatedly 10 times, using add_timer at resolution of 1 jiffy (that is, the timer is scheduled to fire at jiffies + 1). Using the bash script rerun.sh, then I obtain timestamps from printout in syslog, and visualize them using gnuplot.

In most cases, I get a syslog output like this:

[ 7103.055787] Init testjiffy: 0 ; HZ: 250 ; 1/HZ (ms): 4
[ 7103.056044]  testjiffy_timer_function: runcount 1 
[ 7103.060045]  testjiffy_timer_function: runcount 2 
[ 7103.064052]  testjiffy_timer_function: runcount 3 
[ 7103.068050]  testjiffy_timer_function: runcount 4 
[ 7103.072053]  testjiffy_timer_function: runcount 5 
[ 7103.076036]  testjiffy_timer_function: runcount 6 
[ 7103.080044]  testjiffy_timer_function: runcount 7 
[ 7103.084044]  testjiffy_timer_function: runcount 8 
[ 7103.088060]  testjiffy_timer_function: runcount 9 
[ 7103.092059]  testjiffy_timer_function: runcount 10 
[ 7104.095429] Exit testjiffy

... which results with time series and delta histogram plots like these:

This is, essentially, the quality of timing that I'd expect from the code.

However - every once in a while, I get a capture like:

[ 7121.377507] Init testjiffy: 0 ; HZ: 250 ; 1/HZ (ms): 4
[ 7121.380049]  testjiffy_timer_function: runcount 1 
[ 7121.384062]  testjiffy_timer_function: runcount 2 
[ 7121.392053]  testjiffy_timer_function: runcount 3 
[ 7121.396055]  testjiffy_timer_function: runcount 4 
[ 7121.400068]  testjiffy_timer_function: runcount 5 
[ 7121.404085]  testjiffy_timer_function: runcount 6 
[ 7121.408084]  testjiffy_timer_function: runcount 7 
[ 7121.412072]  testjiffy_timer_function: runcount 8 
[ 7121.416083]  testjiffy_timer_function: runcount 9 
[ 7121.420066]  testjiffy_timer_function: runcount 10 
[ 7122.417325] Exit testjiffy

... which results with a rendering like:

... and I'm like: "WHOOOOOAAAAAA ... wait a second..." - isn't there a pulse dropped from the sequence? Meaning that add_timer missed a slot, and then fired up the function in the next 4 ms slot?

The interesting thing is, that in running these tests, I have nothing else but a terminal, web browser and a text editor started up - so I cannot really see anything running, that may hog the OS/kernel; and thus, I really cannot see a reason why the kernel would make such a big miss (of an entire jiffy period). When I read about Linux kernel timing, e.g. "The simplest and least accurate of all timers ... is the timer API", I read that "least accurate" as: "don't expect exactly 4 ms period" (as per this example) - and I don't, I'm fine with the variance shown in the (first) histogram; but I don't expect that a whole period will be missed!?

So my question(s) are:

  • Is this expected behavior from add_timer at this resolution (that a period can occasionally be missed)?
  • If so, is there a way to "force" add_timer to fire the function at each 4ms slot, as specified by a jiffy on this platform?
  • Is it possible that I get a "wrong" timestamp - e.g. the timestamp reflecting when the actual "print" to syslog happened, rather than when the function actually fired?
  • Note that I'm not looking for a period resolution below what corresponds to a jiffy (in this case, 4ms); nor am I looking to decrease the delta variance when the code works properly. So as I see it, I don't have "high resolution timer" demands, nor "hard real-time" demands - I just want add_timer to fire reliably. Would that be possible on this platform, without resorting to special "real-time" configurations of the kernel?

Bonus question: in rerun.sh below, you'll note two sleeps marked with MUSTHAVE; if either of them is left out/commented, OS/kernel freezes, and requires a hard reboot. And I cannot see why - is it really possible that running rmmod after insmod from bash is so fast, that it will conflict with the normal process of module loading/unloading?


Platform info:

$ cat /proc/cpuinfo | grep "processor|model name|MHz|cores"
processor   : 0       # (same for 1)
model name  : Intel(R) Atom(TM) CPU N450   @ 1.66GHz
cpu MHz             : 1000.000
cpu cores   : 1
$ echo $(cat /etc/issue ; uname -a)
Ubuntu 11.04 
 l Linux mypc 2.6.38-16-generic #67-Ubuntu SMP Thu Sep 6 18:00:43 UTC 2012 i686 i686 i386 GNU/Linux
$ echo $(lsb_release -a 2>/dev/null | tr '
' ' ')
Distributor ID: Ubuntu Description: Ubuntu 11.04 Release: 11.04 Codename: natty

Code:

$ cd /tmp/testjiffy
$ ls
Makefile  rerun.sh  testjiffy.c

Makefile:

obj-m += testjiffy.o

all:
    make -C /lib/modules/$(shell uname -r)/build M=$(PWD) modules

clean:
    make -C /lib/modules/$(shell uname -r)/build M=$(PWD) clean

testjiffy.c:

/*
 *  [http://www.tldp.org/LDP/lkmpg/2.6/html/lkmpg.html#AEN189 The Linux Kernel Module Programming Guide]
 */


#include <linux/module.h>   /* Needed by all modules */
#include <linux/kernel.h>   /* Needed for KERN_INFO */
#include <linux/init.h>     /* Needed for the macros */
#include <linux/jiffies.h>
#include <linux/time.h>
#define MAXRUNS 10

static volatile int runcount = 0;
static struct timer_list my_timer;

static void testjiffy_timer_function(unsigned long data)
{
  int tdelay = 100;

  runcount++;
  if (runcount == 5) {
    while (tdelay > 0) { tdelay--; } // small delay
  }

  printk(KERN_INFO
    " %s: runcount %d 
",
    __func__, runcount);

  if (runcount < MAXRUNS) {
    my_timer.expires = jiffies + 1;
    add_timer(&my_timer);
  }
}


static int __init testjiffy_init(void)
{
    printk(KERN_INFO
    "Init testjiffy: %d ; HZ: %d ; 1/HZ (ms): %d
",
               runcount,      HZ,        1000/HZ);

  init_timer(&my_timer);

    my_timer.function = testjiffy_timer_function;
    //my_timer.data = (unsigned long) runcount;

  my_timer.expires = jiffies + 1;
    add_timer(&my_timer);
    return 0;
}

static void __exit testjiffy_exit(void)
{
    printk(KERN_INFO "Exit testjiffy
");
}

module_init(testjiffy_init);
module_exit(testjiffy_exit);

MODULE_LICENSE("GPL");

rerun.sh:

#!/usr/bin/env bash

set -x
make clean
make
# blank syslog first
sudo bash -c 'echo "0" > /var/log/syslog'
sleep 1   # MUSTHAVE 01!
# reload kernel module/driver
sudo insmod ./testjiffy.ko
sleep 1   # MUSTHAVE 02!
sudo rmmod testjiffy
set +x

# copy & process syslog

max=0;
for ix in _testjiffy_*.syslog; do
  aa=${ix#_testjiffy_};
  ab=${aa%.syslog} ;
  case $ab in
    *[!0-9]*) ab=0;;          # reset if non-digit obtained; else
    *) ab=$(echo $ab | bc);;  # remove leading zeroes (else octal)
  esac
  if (( $ab > $max )) ; then
    max=$((ab));
  fi;
done;
newm=$( printf "%05d" $(($max+1)) );
PLPROC='chomp $_;
if (!$p) {$p=0;}; if (!$f) {$f=$_;} else {
  $a=$_-$f; $d=$a-$p;
  print "$a $d
" ; $p=$a;
};'

set -x
grep "testjiffy" /var/log/syslog | cut -d' ' -f7- > _testjiffy_${newm}.syslog
grep "testjiffy_timer_function" _testjiffy_${newm}.syslog 
  | sed 's/[(.*)].*/1/' 
  | perl -ne "$PLPROC" 
  > _testjiffy_${newm}.dat
set +x

cat > _testjiffy_${newm}.gp <<EOF
set terminal pngcairo font 'Arial,10' size 900,500
set output '_testjiffy_${newm}.png'
set style line 1 linetype 1 linewidth 3 pointtype 3 linecolor rgb "red"
set multiplot layout 1,2 title "_testjiffy_${newm}.syslog"
set xtics rotate by -45
set title "Time positions"
set yrange [0:1.5]
set offsets graph 50e-3, 1e-3, 0, 0
plot '_testjiffy_${newm}.dat' using 1:(1.0):xtic(gprintf("%.3se%S",$1)) notitle with points ls 1, '_testjiffy_${newm}.dat' using 1:(1.0) with impulses ls 1
binwidth=0.05e-3
set boxwidth binwidth
bin(x,width)=width*floor(x/width) + width/2.0
set title "Delta diff histogram"
set style fill solid 0.5
set autoscale xy
set offsets graph 0.1e-3, 0.1e-3, 0.1, 0.1
plot '_testjiffy_${newm}.dat' using (bin($2,binwidth)):(1.0) smooth freq with boxes ls 1
unset multiplot
EOF
set -x; gnuplot _testjiffy_${newm}.gp ; set +x


EDIT: Motivated by this comment by @granquet, I tried to obtain scheduler statistics from /proc/schedstat and /proc/sched_debug, by using dd through call_usermodehelper; note that this most of the time "skips" (that is, a file due to the 7th, or 6th, or Xth run of the function would be missing); but I managed to obtain two complete runs, and posted them in https://gist.github.com/anonymous/5709699 (as I noticed gist may be preferred to pastebin on SO), given the output is kinda massive; the *_11* files log a proper run, the *_17* files log a run with a "drop".

Note I also switched to mod_timer_pinned in the module, and it doesn't help much (the gist logs are obtained with the module using this function). These are the changes in testjiffy.c:

#include <linux/kmod.h> // usermode-helper API
...
char fcmd[] = "of=/tmp/testjiffy_sched00";
char *dd1argv[] = { "/bin/dd", "if=/proc/schedstat", "oflag=append", "conv=notrunc", &fcmd[0], NULL };
char *dd2argv[] = { "/bin/dd", "if=/proc/sched_debug", "oflag=append", "conv=notrunc", &fcmd[0], NULL };
static char *envp[] = {
      "HOME=/",
      "TERM=linux",
      "PATH=/sbin:/bin:/usr/sbin:/usr/bin", NULL };

static void testjiffy_timer_function(unsigned long data)
{
  int tdelay = 100;
  unsigned long tjnow;

  runcount++;
  if (runcount == 5) {
    while (tdelay > 0) { tdelay--; } // small delay
  }

  printk(KERN_INFO
    " %s: runcount %d 
",
    __func__, runcount);

  if (runcount < MAXRUNS) {
    mod_timer_pinned(&my_timer, jiffies + 1);
    tjnow = jiffies;
    printk(KERN_INFO
      " testjiffy expires: %lu - jiffies %lu => %lu / %lu
",
      my_timer.expires, tjnow, my_timer.expires-tjnow, jiffies);
    sprintf(fcmd, "of=/tmp/testjiffy_sched%02d", runcount);
    call_usermodehelper( dd1argv[0], dd1argv, envp, UMH_NO_WAIT );
    call_usermodehelper( dd2argv[0], dd2argv, envp, UMH_NO_WAIT );
  }
}

... and this in rerun.sh:

...
set +x

for ix in /tmp/testjiffy_sched*; do
  echo $ix | tee -a _testjiffy_${newm}.sched
  cat $ix >> _testjiffy_${newm}.sched
done
set -x ; sudo rm /tmp/testjiffy_sched* ; set +x

cat > _testjiffy_${newm}.gp <<EOF
...


I'll use this post for verbose replying.

@CL.: many thanks for the answer. Good to have it confirmed that it's "possible that your timer function gets called at a later jiffy"; by logging the jiffies, I too realized that the timer function gets called at a later time - and other than that, it doesn't anything "wrong" per se.

Good to know about the timestamps; I wonder if it is possible that: the timer functions hits at the right time, but the kernel preempts the kernel logging service (I believe it's klogd), so I get a delayed timestamp? However, I'm trying to create a "looped" (or rather, periodic) timer function to write to hardware, and I first noted this "drop" by realizing the PC doesn't write data at certain intervals on the USB bus; and given that the timestamps confirm that behavior, it's probably not the problem here (I guess).

I have modified the timer function so it fires relative to the scheduled time of the last timer (my_timer.expires) - again via mod_timer_pinned instead of add_timer:

static void testjiffy_timer_function(unsigned long data)
{
  int tdelay = 100;
  unsigned long tjlast;
  unsigned long tjnow;

  runcount++;
  if (runcount == 5) {
    while (tdelay > 0) { tdelay--; } // small delay
  }

  printk(KERN_INFO
    " %s: runcount %d 
",
    __func__, runcount);

  if (runcount < MAXRUNS) {
    tjlast = my_timer.expires;
    mod_timer_pinned(&my_timer, tjlast + 1);
    tjnow = jiffies;
    printk(KERN_INFO
      " testjiffy expires: %lu - jiffies %lu => %lu / %lu last: %lu
",
      my_timer.expires, tjnow, my_timer.expires-tjnow, jiffies, tjlast);
  }
}

... and the first few tries, it works impeccably - however, eventually, I get this:

[13389.775508] Init testjiffy: 0 ; HZ: 250 ; 1/HZ (ms): 4
[13389.776051]  testjiffy_timer_function: runcount 1 
[13389.776063]  testjiffy expires: 3272445 - jiffies 3272444 => 1 / 3272444 last: 3272444
[13389.780053]  testjiffy_timer_function: runcount 2 
[13389.780068]  testjiffy expires: 3272446 - jiffies 3272445 => 1 / 3272445 last: 3272445
[13389.788054]  testjiffy_timer_function: runcount 3 
[13389.788073]  testjiffy expires: 3272447 - jiffies 3272447 => 0 / 3272447 last: 3272446
[13389.788090]  testjiffy_timer_function: runcount 4 
[13389.788096]  testjiffy expires: 3272448 - jiffies 3272447 => 1 / 3272447 last: 3272447
[13389.792070]  testjiffy_timer_function: runcount 5 
[13389.792091]  testjiffy expires: 3272449 - jiffies 3272448 => 1 / 3272448 last: 3272448
[13389.796044]  testjiffy_timer_function: runcount 6 
[13389.796062]  testjiffy expires: 3272450 - jiffies 3272449 => 1 / 3272449 last: 3272449
[13389.800053]  testjiffy_timer_function: runcount 7 
[13389.800063]  testjiffy expires: 3272451 - jiffies 3272450 => 1 / 3272450 last: 3272450
[13389.804056]  testjiffy_timer_function: runcount 8 
[13389.804072]  testjiffy expires: 3272452 - jiffies 3272451 => 1 / 3272451 last: 3272451
[13389.808045]  testjiffy_timer_function: runcount 9 
[13389.808057]  testjiffy expires: 3272453 - jiffies 3272452 => 1 / 3272452 last: 3272452
[13389.812054]  testjiffy_timer_function: runcount 10 
[13390.815415] Exit testjiffy

... which renders like so:

... so, basically I have a delay/"drop" at +8ms slot (which should be @3272446 jiffies), and then have two functions run at the +12ms slot (which would be @ 3272447 jiffies); you can even see the label on the plot as "more bolded" because of it. This is better, in the sense of the "drop" sequence now being synchronous to a proper, non-drop sequence (which is as you said: "to avoid that one late timer function shifts all following timer calls") - however, I still miss a beat; and since I have to write bytes to hardware at each beat, so I keep a sustained, constant transfer rate, this unfortunately doesn't help me much.

As for the other suggestion, to "use ten timers" - because of my ultimate goal (write to hardware using a periodic lo-res timer function); I thought at first it doesn't apply - but if nothing else is possible (other than doing some special real-time kernel preparations), then I'll certainly try a scheme where I have 10 (or N) timers (maybe stored in an array) which are fired periodically one after another.


EDIT: just adding leftover relevant comments:

USB transfers are either scheduled in advance (isochronous) or have no timing guarantees (asynchronous). If your device doesn't use isochronous transfers, it's badly misdesigned. – CL. Jun 5 at 10:47

Thanks for the comment, @CL. - "... scheduled in advance (isochronous)..." cleared a confusion I had. I'm (eventually) targeting an FT232, which only has BULK mode - and as long as the bytes per timer hit is low, I can actually "cheat" my way through in "streaming" data with add_timer; however, when I transfer ammount of bytes close to consuming bandwidth, then these "misfires" start getting noticeable as drops. So I was interested in testing the limits of that, for which I need a reliably repetitive "timer" function - is there anything else I could try to have a reliable "timer"? – sdaau Jun 5 at 12:27

@sdaau Bulk transfers are not suitable for streaming. You cannot fix shortcomings in the hardware protocol by using another kind of software timer. – CL. Jun 5 at 13:50

... and as my response to @CL. : I'm aware I wouldn't be able to fix shortcomings; I was more interested in observing these shortcomings - say, if a kernel function makes a periodic USB write, I could observe the signals on a scope/analyzer, and hopefully see in what sense is the bulk mode unsuitable. But first, I'd have to trust that the function can (at least somewhat) reliably repeat at a periodic rate (i.e. "generate" a clock/tick) - and I wasn't aware, until now, that I cannot really trust add_timer at jiffies resolution (as it is capable of relatively easily skipping a whole period). However, it seems that moving to Linux' high-resolution timers (hrtimer) does give me a reliable periodic function in this sense - so I guess that solves my problem (posted in my answer below).

解决方案

Many thanks for all the comments and answers; they all pointed to things that must be taken into account - but given I'm somewhat of a forever noob, I still needed to do some more reading, before gaining some understanding (I hope a correct one). Also, I couldn't really find anything specific for periodically "ticking" functions - so I'll post a more verbose answer here.

In brief - for a reliable periodic Linux kernel function at a resolution of a jiffy, do not use add_timer (<linux/time.h>), as it may "drop" an entire period; use high-resolution timers (<linux/hrtimer.h>) instead. In more detail:

Is it possible that I get a "wrong" timestamp - ...?

@CL.: The timestamp in the log is the time when that string was printed to the log.

So, maybe it's possible - but it turns out, that's not the problem here:

Is this expected behavior from add_timer at this resolution (that a period can occasionally be missed)?

I guess, it turns out - yes:

If so, is there a way to "force" add_timer to fire the function at each 4ms slot, as specified by a jiffy on this platform?

... and (I guess again), it turns out - no.

Now, the reasons for this are somewhat subtle - and I hope if I didn't get them right, someone will correct me. First of all, the first misconception that I had, was that "a clock is just a clock" (in the sense of: even if it is implemented as computer code) - but that is not quite correct. The kernel basically has to "queue" an "event" somewhere, each time something like add_timer is used; and this request may come from anything really: from any (and all) sort(s) of driver(s), or even possibly userspace.

The problem is that this "queuing" costs - since in addition to the kernel having to handle (the equivalent of) traversing and inserting (and removing) items in an array, it also has to handle timer delays spanning several orders of magnitude (from say milliseconds to maybe 10s of seconds); and the fact that some drivers (like, apparently, those for network protocols) apparently queue a lot of timer events, which are usually cancelled before running - while other types may require a completely different behavior (like in my case - in a periodic function, you expect that most of the time, the event will usually not be cancelled; and you also queue the events one by one). On top of that, the kernel needs to handle this for uniprocessor vs. SMP vs. multiprocessor platforms. Thus, there is a cost-benefit tradeoff involved in implementing timer handling in the kernel.

It turns out, the architecture around jiffies/add_timer is designed to handle the most common devices - and for them, precision at a resolution of a jiffy is not an issue; but this also means that one cannot expect a reliable timer at resolution of a single jiffy with this method. This is also compounded by the fact that the kernel handles these "event queues" by treating them (somewhat) like interrupt service requests (IRQ); and that there are several levels of priority in IRQ handling in the kernel, where higher priority routine can pre-empt a lower priority one (that is: interrupt and suspend a lower priority routine, even if it is being executed at the time - and allow the higher priority routine to go about its business). Or, as previously noted:

@granquet: timers run in soft irq context, which means they have the highest priority and they preempt everything running/runnable on the CPU ... but hardware interrupts which are not disabled when servicing a soft irq. So you might (most probable explanation) get an Hardware interrupt here and there that preempts your timer ... and thus you get an interrupt that is not serviced at the right time.

@CL.: It is indeed possible that your timer function gets called at a later jiffy than what expires what set to. Possible reasons are scheduling delays, other drivers that disable interrupts for too long (graphics and WLAN drivers are usual culprits), or some crappy BIOS executing SMI code.

I now think so, too - I think this could be an illustration of what happens:

  • jiffies changes to, say, 10000 (== 40000 ms @250 Hz)
  • Let's say the timer function, (queued by add_timer) is about to start running - but hasn't started running yet
  • Let's say here, the network card generates (for whatever reason) a hardware interrupt
  • The hardware interrupt, having a higher priority, triggers the kernel to pre-empt (stop and suspend) the timer function (possibly started by now, and just few instructions in);
  • That means the kernel now has to reschedule the timer function, to run at a later point - and since one only works with integer operations in the kernel, and time resolution for this kind of event is in jiffies - the best it can do is reschedule it for jiffies+1 (10001 == 40004 ms @250 Hz)
  • Now the kernel switches the context to the IRQ service routine of the network card driver, and it goes about its business
  • Let's say the IRQ service routine completes in 200 μs - that means now we're (in "absolute" terms) at 40000.2 ms - however, we are also still at 10000 jiffies
  • If the kernel now switched the context back to the timer function, it would have completed - without me necessarily noticing the delay;
  • ... however, that will not happen, because the timer function is scheduled for the next jiffy!
  • So kernel goes about its business (possibly sleeping) for the next approx 3.8 ms
  • jiffies changes to 10001 (== 40004 ms @250 Hz)
  • (the previously rescheduled) timer function runs - and this time completes without interruption

I haven't really done a detailed analysis to see if the sequence of events is exactly as described above; but I'm quite persuaded that it is something close - in other words, a resolution problem - especially since the high-resolution timer approach seems to not show this behavior. It would be great indeed, to obtain a scheduler log, and know exactly what happened to cause a pre-empt - but I doubt the roundtrip to userspace, which I attempted in OP edit, in response to @granquet's comment, is the right thing to do.

In any case, going back to this:

Note that I'm not looking for a period resolution below what corresponds to a jiffy (in this case, 4ms); nor am I looking to decrease the delta variance when the code works properly. So as I see it, I don't have "high resolution timer" demands, nor "hard real-time" demands ...

... here was a bad mistake I made - as the analysis above shows, I did have "high resolution" demands! And had I realized that earlier, I may have found relevant reading sooner. Anyways, some relevant docs - even if they don't discuss specifically periodic functions - for me, were:

  • LDD3: 5.3. Semaphores and Mutexes - (in describing a driver with different demands from here): "no accesses will be made from interrupt handlers or other asynchronous contexts. There are no particular latency (response time) requirements; application programmers understand that I/O requests are not usually satisfied immediately"
  • Documentation/timers/hrtimers.txt - "The timers.c code is very "tightly coded" around jiffies and 32-bitness assumptions, and has been honed and micro-optimized for a relatively narrow use case (jiffies in a relatively narrow HZ range) for many years - and thus even small extensions to it easily break the wheel concept"
  • T. Gleixner, D. Niehaus Hrtimers and Beyond: Transforming the Linux Time Subsystems (pdf) - (most detailed, see also diagrams inside) "The Cascading Timer Wheel (CTW), which was implemented in 1997, replaced the original time ordered double linked list to resolve the scalability problem of the linked list's O(N) insertion time... The current approach to timer management in Linux does a good job of satisfying an extremely wide range of requirements, but it cannot provide the quality of service required in some cases precisely because it must satisfy such a wide range of requirements... The timeout related timers are kept in the existing timer wheel and a new subsystem optimized for (high resolution) timer requirements hrtimers was implemented. hrtimers are entirely based on human time (units: nanoseconds)... They are kept in a time sorted, per-CPU list, implemented as a red-black tree."
  • The high-resolution timer API [LWN.net] - "At its core, the hrtimer mechanism remains the same. Rather than using the "timer wheel" data structure, hrtimers live on a time-sorted linked list, with the next timer to expire being at the head of the list. A separate red/black tree is also used to enable the insertion and removal of timer events without scanning through the list. But while the core remains the same, just about everything else has changed, at least superficially."
  • Software interrupts and realtime [LWN.net] - "The softirq mechanism is meant to handle processing that is almost — but not quite — as important as the handling of hardware interrupts. Softirqs run at a high priority (though with an interesting exception, described below), but with hardware interrupts enabled. They thus will normally preempt any work except the response to a "real" hardware interrupt... Starting with the 3.0 realtime patch set, though, that capability went away... In response, in 3.6.1-rt1, the handling of softirqs has changed again."
  • High- (but not too high-) resolution timeouts [LWN.net] - "_poll() and epoll_wait() take an integer number of milliseconds; select() takes a struct timeval with microsecond resolution, and ppoll() and pselect() take a struct timespec with nanosecond resolution. They are all the same, though, in that they convert this timeout value to jiffies, with a maximum resolution between one and ten milliseconds. A programmer might program a pselect() call with a 10 nanosecond timeout, but the call may not return until 10 milliseconds later, even in the absence of contention for the CPU. ... It's a useful feature, but it comes at the cost of some significant API changes._"

One thing clear from the quotes, is that high-resolution timing facilities are still under active development (with API changes) in the kernel - and I was afraid, that maybe I'd have to install a special "real-time patch" kernel. Thankfully, high-resolution timers are seemingly available (and working) in my 2.6.38-16 SMP kernel without any special changes. Below is the listing of the modified testjiffies.c kernel module, which now uses high-resolution timers, but otherwise keeps the same period as determined by jiffies. For testing, I made it loop for 200 times (instead of 10 in the OP); and running the rerun.sh script for some 20-30 times, this is the worst result I got:

The time sequence is now obviously unreadable, but the histogram can still tell us this: taking 0.00435-0.004 (= 0.004-0.00365) = 350 μs for the max deviation, it represents only 100*(350/4000) = 8.75% of the expected period; which I certainly don't have a problem with. Additionally, I never got a drop (or correspondingly, an entire 2*period = 8 ms delay), or a 0 ms delay - the captures I got, are otherwise of the quality shown on the first image in OP. Now, of course I could run a longer test and see more precisely how reliable it is - but this is all the reliability I'd expect/need to see for this simple case; contrast that to the OP, where I'd get a drop in just 10 loops, with the probability of tossing a coin - every second or third run of the rerun.sh script, I'd get a drop - even in context of low OS resource usage!

Finally, note that the source below should have the problem, spotted by @CL.: "Your module is buggy: you must ensure that the timer is not pending before the module is unloaded", fixed (in the context of hrtimer). This seemingly answers my bonus question, as it obviates the need for either of the "MUSTHAVE" sleeps in the rerun.sh script. However, note that as 200 loops @ 4 ms take 0.8 s - the sleep between insmod and rmmod is needed if we want a full 200 tick capture (otherwise, on my machine, I get only some 7 ticks captured).

Well, hope I got this right now (at least most if it) - if not, corrections are welcome :)

testjiffy(-hr).c

#include <linux/module.h>   /* Needed by all modules */
#include <linux/kernel.h>   /* Needed for KERN_INFO */
#include <linux/init.h>     /* Needed for the macros */
#include <linux/jiffies.h>
#include <linux/time.h>
#define MAXRUNS 200

#include <linux/hrtimer.h>


static volatile int runcount = 0;

//~ static struct timer_list my_timer;
static unsigned long period_ms;
static unsigned long period_ns;
static ktime_t ktime_period_ns;
static struct hrtimer my_hrtimer;


//~ static void testjiffy_timer_function(unsigned long data)
static enum hrtimer_restart testjiffy_timer_function(struct hrtimer *timer)
{
  int tdelay = 100;
  unsigned long tjnow;
  ktime_t kt_now;
  int ret_overrun;

  runcount++;
  if (runcount == 5) {
    while (tdelay > 0) { tdelay--; } // small delay
  }

  printk(KERN_INFO
    " %s: runcount %d 
",
    __func__, runcount);

  if (runcount < MAXRUNS) {
    tjnow = jiffies;
    kt_now = hrtimer_cb_get_time(&my_hrtimer);
    ret_overrun = hrtimer_forward(&my_hrtimer, kt_now, ktime_period_ns);
    printk(KERN_INFO
      " testjiffy jiffies %lu ; ret: %d ; ktnsec: %lld 
",
      tjnow, ret_overrun, ktime_to_ns(kt_now));
    return HRTIMER_RESTART;
  }
  else return HRTIMER_NORESTART;
}


static int __init testjiffy_init(void)
{
  struct timespec tp_hr_res;
  period_ms = 1000/HZ;
  hrtimer_get_res(CLOCK_MONOTONIC, &tp_hr_res);
  printk(KERN_INFO
    "Init testjiffy: %d ; HZ: %d ; 1/HZ (ms): %ld ; hrres: %lld.%.9ld
",
               runcount,      HZ,        period_ms, (long long)tp_hr_res.tv_sec, tp_hr_res.tv_nsec );

  hrtimer_init(&my_hrtimer, CLOCK_MONOTONIC, HRTIMER_MODE_REL);
  my_hrtimer.function = &testjiffy_timer_function;
  period_ns = period_ms*( (unsigned long)1E6L );
  ktime_period_ns = ktime_set(0,period_ns);
  hrtimer_start(&my_hrtimer, ktime_period_ns, HRTIMER_MODE_REL);

  return 0;
}

static void __exit testjiffy_exit(void)
{
  int ret_cancel = 0;
  while( hrtimer_callback_running(&my_hrtimer) ) {
    ret_cancel++;
  }
  if (ret_cancel != 0) {
    printk(KERN_INFO " testjiffy Waited for hrtimer callback to finish (%d)
", ret_cancel);
  }
  if (hrtimer_active(&my_hrtimer) != 0) {
    ret_cancel = hrtimer_cancel(&my_hrtimer);
    printk(KERN_INFO " testjiffy active hrtimer cancelled: %d (%d)
", ret_cancel, runcount);
  }
  if (hrtimer_is_queued(&my_hrtimer) != 0) {
    ret_cancel = hrtimer_cancel(&my_hrtimer);
    printk(KERN_INFO " testjiffy queued hrtimer cancelled: %d (%d)
", ret_cancel, runcount);
  }
  printk(KERN_INFO "Exit testjiffy
");
}

module_init(testjiffy_init);
module_exit(testjiffy_exit);

MODULE_LICENSE("GPL");

这篇关于Linux 内核 add_timer 在分辨率为一瞬间的可靠性?的文章就介绍到这了,希望我们推荐的答案对大家有所帮助,也希望大家多多支持IT屋!

查看全文
登录 关闭
扫码关注1秒登录
发送“验证码”获取 | 15天全站免登陆