介绍：
NAME
xentrace - capture Xen trace buffer data
SYNOPSIS
xentrace [ OPTIONS ] [ FILE ]
DESCRIPTION
xentrace is used to capture trace buffer data from Xen. The data is output in the following binary format (host endian): CPU(uint) TSC(u64) EVENT(u32) D1 D2 D3 D4 D5 (all u32)Where CPU is the processor number, TSC is the record's timestamp (the value of the CPU cycle counter), EVENT is the event ID and D1...D5 are the trace data.
Data is dumped onto the standard output (which must not be a TTY) or a FILE specified on the command line.
The output should be parsed using the tool xentrace_format, which can produce human-readable output in ASCII format.
简单来说，xentrace是用来获取系统运行过程中一些动态信息的工具，类似Windows下的日志。
一般使用：
系统启动xen之后，就可以使用xentrace和xentrace_format命令了。
获取输出命令：xentrace -D -T 10 rec.raw
其中-D参数表明清空之前缓存的数据
-T后面跟的时间，表示需要获取多长时间的数据（从该命令执行起开始，单位是s）
将输出格式化为可读信息命令：cat rec.raw | xentrace_format formats >rec.txt
其中formats文件是xen目录中带的，一般在tools/xentrace下
原理探究：
查看xen源代码可以知道，通过xentrace获取的数据是通过TRACE_2D、TRACE_3D（2D、3D中2和3是指参数的个数）等这些记录的数据，例如：
/xen/common/schedule.c
243 void vcpu_wake(struct vcpu *v)
244 {
.................
270 TRACE_2D(TRC_SCHED_WAKE, v->domain->domain_id, v->vcpu_id);
271 }
看一下TRACE_2D的实现代码：
/xen/include/xen/trace.h
64 #define TRACE_2D(_e,d1,d2) \
65 do { \
66 if ( unlikely(tb_init_done) ) \
67 { \
68 u32 _d[2]; \
69 _d[0] = d1; \
70 _d[1] = d2; \
71 __trace_var(_e, 1, sizeof(*_d)*2, (unsigned char *)_d); \
72 } \
73 } while ( 0 )
可以看出，真正写到缓冲区是通过__trace_var函数来实现的，下面来简略看一下__trace_var
/xen/common/trace.c
416 /**
417 * trace - Enters a trace tuple into the trace buffer for the current CPU.
418 * @event: the event type being logged
419 * @d1...d5: the data items for the event being logged
420 *
421 * Logs a trace record into the appropriate buffer. Returns nonzero on
422 * failure, otherwise 0. Failure occurs only if the trace buffers are not y et
423 * initialised.
424 */
这个函数将当前的trace信息输出到log中去，方便我们后面的读取
425 void __trace_var(u32 event, int cycles, int extra, unsigned char *extra_data )
426 {
................. //具体的实现我们就不细究了，有兴趣的可以去分析一下
550 }
回到之前的代码
270 TRACE_2D(TRC_SCHED_WAKE, v->domain->domain_id, v->vcpu_id);
这个函数中第一个参数是事件类型，后面是相应的数据，事件类型定义在trace.h文件中，调度这块研究中使用较多的有以下一些：
/xen/include/public/trace.h
56 #define TRC_SCHED_VERBOSE 0x00028000 /* More inclusive scheduling */
.............
63 #define TRC_SCHED_RUNSTATE_CHANGE (TRC_SCHED_MIN + 1)
64 #define TRC_SCHED_CONTINUE_RUNNING (TRC_SCHED_MIN + 2)
65 #define TRC_SCHED_DOM_ADD (TRC_SCHED_VERBOSE + 1)
66 #define TRC_SCHED_DOM_REM (TRC_SCHED_VERBOSE + 2)
67 #define TRC_SCHED_SLEEP (TRC_SCHED_VERBOSE + 3)
68 #define TRC_SCHED_WAKE (TRC_SCHED_VERBOSE + 4)
69 #define TRC_SCHED_YIELD (TRC_SCHED_VERBOSE + 5)
70 #define TRC_SCHED_BLOCK (TRC_SCHED_VERBOSE + 6)
71 #define TRC_SCHED_SHUTDOWN (TRC_SCHED_VERBOSE + 7)
72 #define TRC_SCHED_CTL (TRC_SCHED_VERBOSE + 8)
73 #define TRC_SCHED_ADJDOM (TRC_SCHED_VERBOSE + 9)
74 #define TRC_SCHED_SWITCH (TRC_SCHED_VERBOSE + 10)
75 #define TRC_SCHED_S_TIMER_FN (TRC_SCHED_VERBOSE + 11)
76 #define TRC_SCHED_T_TIMER_FN (TRC_SCHED_VERBOSE + 12)
77 #define TRC_SCHED_DOM_TIMER_FN (TRC_SCHED_VERBOSE + 13)
78 #define TRC_SCHED_SWITCH_INFPREV (TRC_SCHED_VERBOSE + 14)
79 #define TRC_SCHED_SWITCH_INFNEXT (TRC_SCHED_VERBOSE + 15)
..............
97 /* Indicates that addresses in trace record are 64 bits */ //标识64位系统
98 #define TRC_64_FLAG (0x100)
TRACE_2D的数据最终会以二进制形式存储（为了节省存储空间），通过xentrace_format可以将二进制数据转换为可读的ASCII编码的数据
xentrace_format命令最终是根据参数中formats对应文件中的数据格式来对二进制数据解释的，下面来分析一下formats文件：
/tools/xentrace/formats
20 0x00028001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) sched_add_domain [ domid = 0x%(1)08x, edomid = 0x%(2)08x ]
21 0x00028002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) sched_rem_domain [ domid = 0x%(1)08x, edomid = 0x%(2)08x ]
22 0x00028003 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) domain_sleep [ domid = 0x%(1)08x, edomid = 0x%(2)08x ]
23 0x00028004 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) domain_wake [ domid = 0x%(1)08x, edomid = 0x%(2)08x ]
0x00028004是事件类型标识，可以看到0x00028004就是TRC_SCHED_WAKE，domid = 0x%(1)08x, edomid = 0x%(2)08x中（1）表示第一个参数（即dom_id)，（2）表示第二个参数（即vcpu_id)
至此我们已经大概了解了xentrace的原理，下面来看一下xentrace的进阶使用——如何添加自己所需要的输出
进阶使用（需要修改xen源代码，并重新编译，慎用！）：
了解了xentrace的原理之后，那么我们就可以来试着添加一些我们自己想要的事件类型了，首先在trace.h头文件中定义一个TEST类型事件：
/xen/include/public/trace.h
80 #define TRC_SCHED_TEST (TRC_SCHED_VERBOSE + 16)
然后我们想记录一下credit调度中tickle的情况，于是在credit调度算法中添加如下一个trace输出：
/xen/common/sched_credit.c
800 static void
801 csched_acct(void* dummy)
802 {
...........
823 // added by spri1987
824 TRACE_2D(TRC_SCHED_TEST, current->domain->domain_id, current->vcpu_id);
825 // end
............
1000 }
OK，xen源代码修改完毕，为了能够生效，我们需要重新编译我们的xen，可以使用make xen命令来编译，编译之后重启系统即可生效。
下面我们来测试下我们添加的TRACE是否有记录，获取一个10s的TRACE信息：
xentrace -D -T 10 rec.raw
获取之后，我们需要通过formats来格式化该二进制数据。由于我们添加了新的事件类型，因此我们需要先修改我们的formats文件：
tools/xentrace/formats
26 0x00028010 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) do_tickle [ domid = 0x%(1)08x, edomid = 0x%(2)08x ]
修改之后保存，然后执行如下命令：
cat rec.raw | xentrace_format formats >rec.txt
这个命令执行需要一些时间，慢慢等待会。。。
完成之后查看我们生成的rec.txt文件，查找tickle，如果可以看到类似如下的记录：
14200 CPU0 519304896957 (+ 1183) do_tickle [ domid = 0x00007fff, edomid = 0x00000000 ]
congratulations！ ^-^
by spri1987 2010-6-22
本文转自feisky博客园博客，原文链接：http://www.cnblogs.com/feisky/archive/2012/01/18/2325957.html，如需转载请自行联系原作者
