在下面给出的代码中，有一个简单的 Linux 内核模块（驱动程序），它重复调用一个函数 10 次，使用add_timer分辨率为 1 jiffy（即，定时器计划在 触发jiffies + 1）。使用bash脚本rerun.sh，然后我从打印输出中获取时间戳syslog，并使用gnuplot.
在大多数情况下，我得到这样的syslog输出：
[ 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
...结果是时间序列和增量直方图，如下所示：
从本质上讲，这就是我期望从代码中获得的时间质量。
然而 - 每隔一段时间，我就会得到一个像这样的捕获：
[ 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
...结果如下：
......我想：“WHOOOOOAAAAAA......等一下......” - 序列中没有脉冲吗？这意味着add_timer 错过了一个插槽，然后在接下来的 4 毫秒插槽中启动了该功能？
有趣的是，在运行这些测试时，我只有一个终端、网络浏览器和一个文本编辑器启动了——所以我看不到任何正在运行的东西，这可能会占用操作系统/内核；因此，我真的看不出内核为什么会出现如此大的失误（整个短暂的时期）。当我阅读有关 Linux 内核计时的信息时，例如“所有计时器中最简单和最不准确的......是计时器 API ”，我将“最不准确”读为：“不要期望正好4 毫秒的周期”（根据这个示例） - 我没有，我对（第一个）直方图中显示的方差很好；但我不指望会错过整个时期！？
所以我的问题是：
- 这是此分辨率的预期行为
add_timer（偶尔会错过一段时间）吗？ - 如果是这样，有没有办法“强制”
add_timer在每个 4ms 时隙触发函数，正如这个平台上的 jiffy 所指定的那样？ - 我是否有可能得到一个“错误”的时间戳 - 例如反映实际“打印”到系统日志的时间戳，而不是函数实际触发的时间？
- 请注意，我不是在寻找低于对应于 jiffy（在本例中为 4ms）的周期分辨率；当代码正常工作时，我也不希望减少增量方差。所以在我看来，我没有“高分辨率计时器”的要求，也没有“硬实时”的要求——我只想
add_timer可靠地发射。在这个平台上这是否可能，而无需求助于内核的特殊“实时”配置？
额外问题：在rerun.sh下面，您会注意到两个sleep标有MUSTHAVE; 如果其中任何一个被遗漏/注释，操作系统/内核会冻结，并且需要硬重启。而且我不明白为什么 -从 bashrmmod之后运行真的有可能如此之快，以至于它会与模块加载/卸载的正常过程发生冲突吗？insmod
平台信息：
$ 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 \n \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 '\n' ' ')
Distributor ID: Ubuntu Description: Ubuntu 11.04 Release: 11.04 Codename: natty
代码：
$ 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 \n",
__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\n",
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\n");
}
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\n" ; $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
编辑：受到@granquet 的评论的启发，我尝试从/proc/schedstatand获取调度程序统计信息/proc/sched_debug，通过使用ddthrough call_usermodehelper; 请注意，这在大多数情况下会“跳过”（即，由于函数的第 7 次、第 6 次或第 X 次运行而导致的文件将丢失）；但我设法获得了两次完整的运行，并将它们发布在https://gist.github.com/anonymous/5709699中（因为我注意到在 SO 上 gist 可能比 pastebin 更受欢迎），因为输出有点大；文件记录了*_11*正确的运行，*_17*文件记录了带有“drop”的运行。
注意我也在mod_timer_pinned模块中切换到，并没有太大帮助（gist日志是使用该功能的模块获得的）。这些是 中的变化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 \n",
__func__, runcount);
if (runcount < MAXRUNS) {
mod_timer_pinned(&my_timer, jiffies + 1);
tjnow = jiffies;
printk(KERN_INFO
" testjiffy expires: %lu - jiffies %lu => %lu / %lu\n",
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 );
}
}
...这在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
...
我将使用这篇文章进行详细回复。
@CL。: 非常感谢您的回答。很高兴它确认“您的计时器函数可能会在稍后的瞬间被调用”；通过记录 jiffies，我也意识到计时器函数会在稍后被调用 - 除此之外，它本身并没有任何“错误”。
很高兴了解时间戳；我想知道是否有可能：定时器功能在正确的时间命中，但内核抢占内核日志服务（我相信它是klogd），所以我得到一个延迟的时间戳？但是，我正在尝试创建一个“循环”（或者更确切地说，周期性）定时器函数来写入硬件，我首先注意到这个“下降”是通过意识到 PC 不会以特定间隔在 USB 总线上写入数据；并且鉴于时间戳证实了这种行为，这可能不是这里的问题（我猜）。
我已经修改了计时器功能，因此它相对于最后一个计时器（my_timer.expires）的预定时间触发 - 再次通过mod_timer_pinned而不是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 \n",
__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\n",
my_timer.expires, tjnow, my_timer.expires-tjnow, jiffies, tjlast);
}
}
...在最初的几次尝试中，它的效果无可挑剔-但是，最终，我得到了这个：
[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
...呈现如下：
...所以，基本上我在 +8ms 插槽（应该是 @3272446 jiffies）有一个延迟/“丢弃”，然后在 +12ms 插槽（应该是 @3272447 jiffies）运行两个函数；您甚至可以因此将绘图上的标签视为“更粗体”。这更好，因为“丢弃”序列现在与正确的非丢弃序列同步（正如您所说：“避免一个迟到的定时器函数转移所有后续定时器调用”） - 但是，我仍然错过一个节拍；而且由于我必须在每次节拍时将字节写入硬件，所以我保持持续、恒定的传输速率，不幸的是，这对我没有多大帮助。
至于另一个建议，“使用十个定时器” - 因为我的最终目标（使用周期性低分辨率定时器功能写入硬件）；起初我认为它不适用 - 但如果没有其他可能（除了做一些特殊的实时内核准备），那么我肯定会尝试一个我有 10 个（或 N 个）定时器的方案（可能存储在一个数组）一个接一个周期性地触发。
编辑：只需添加剩余的相关评论：
USB 传输要么提前安排（同步），要么没有时间保证（异步）。如果您的设备不使用同步传输，那么它的设计严重错误。- CL。6 月 5 日 10:47
感谢您的评论，@CL。- “......提前安排（同步）......”消除了我的困惑。我（最终）瞄准了一个只有 BULK 模式的 FT232——只要每个定时器命中的字节数很低，我实际上可以用 add_timer 在“流式传输”数据中“作弊”；但是，当我传输接近消耗带宽的字节时，这些“失火”开始随着下降而变得明显。所以我有兴趣测试它的限制，为此我需要一个可靠的重复“计时器”功能 - 还有什么我可以尝试拥有一个可靠的“计时器”吗？– sdaau 6 月 5 日 12:27
@sdaau 批量传输不适合流式传输。您无法通过使用另一种软件定时器来修复硬件协议中的缺点。- CL。6月5日 13:50
...作为我对@CL 的回应。: 我知道我无法弥补缺点；我对观察这些缺点更感兴趣——比如，如果一个内核函数进行定期 USB 写入，我可以观察示波器/分析仪上的信号，并希望看到批量模式在什么意义上是不合适的。但首先，我必须相信该函数可以（至少在某种程度上）可靠地以周期性速率重复（即“生成”一个时钟/滴答声）——直到现在我才意识到我不能真正相信add_timer在 jiffies 分辨率下（因为它能够相对轻松地跳过整个周期）。但是，似乎转移到 Linux'hrtimer）。
