下面这段DTrace脚本是在一个函数的入口和出口都打印一条log输出:
pid$1::func:entry, pid$1::func:return { printf("%Y [%d][%s][%s]\n", walltimestamp, tid, probefunc, probename); }
在多核CPU系统上运行,有可能函数退出时的log输出会先于进入时的log输出。类似这样:
2014 Mar 3 02:13:49 [57][func][return] 2014 Mar 3 02:14:04 [57][func][entry]
这是因为在多核CPU系统上,DTrace的输出会被缓存到每个CPU的buffer里。这样如果entry的log被缓存到CPU 1 的buffer里,return的log被缓存到CPU 2 的buffer里,而CPU 2 buffer里的log先输出出来,就会出现上述这个情况。可以在log里增加对当前CPU的打印(DTrace 内置变量:cpu),就可以更好地理解这个问题。
关于这个问题,可参考stackoveflow的帖子:http://stackoverflow.com/questions/22137990/why-the-dtrace-doesnt-output-function-return-log。