试试SPDK的trace
作者简介：
刘孝冬 Intel 高级软件工程师
专注于开源存储SPDK及ISA-L软件的开发。
1
SPDK Trace
介绍
软件开发人员需要了解程序运行时的行为，以便在出现故障时做代码调试，或性能分析时查找热点。通常当日志所记录的信息无法提供足够细节、无法包含足够类型时，软件跟踪技术(Trace)就会被用来记录特定相关类型事件的发生和相应上下文信息，并将记录内容写入到指定文件内，待后续分析使用。
SPDK中有一个跟踪框架*SPDK tracing，用于在运行时捕获底层事件信息。跟踪点(Tracepoint)提供了一个在运行时可行的高性能跟踪机制。它们被实现为共享内存中的环形缓冲区，这样在SPDK进程向环形缓冲区写入记录时，其他进程也可以访问缓冲区上的内容。
Figure1 Diagram of SPDK trace utility
SPDK内多个应用和函数库已经使用SPDK tracing的跟踪点进行监测，以支持对性能和进程崩溃进行分析。不过，目前对SPDK tracing 框架的规范化和相应文档还在进行中。
2
如何使能SPDK的
trace功能
默认情况下，即使在configure时未使能debug flag，SPDK的trace库libspdk_trace.a是会被编译链接到相应SPDK应用中。但tracing功能在运行时是默认关闭的。若要开启SPDK tracing功能，有两种方法，一是在启动SPDK应用时，通过--tpoint-group-mask (-e)参数指定要开启tracing功能的模块；或者通过SPDK trace RPC方法来开启或关闭某些模块的tracing功能。
Tracing功能被使能后，一旦相应事件一发生，SPDK进程就会准备在它对应的trace文件中写入相应事件信息。目前SPDK应用的trace文件会写入到/dev/shm下，它以SPDK应用名称，加“_trace.pid”，再加应用的进程ID号，如bdev_svc_trace.pid67924。
3
SPDK的trace
工具
SPDK目前有两个trace相关的工具，spdk_trace (位置app/trace目录下)和spdk_trace_record (位于app/trace_record目录下)。其中，spdk_trace_record用于转储share memory下trace文件到其他位置。Spdk_trace用于查看trace文件内容，以便进行相关分析。
Figure2 usage of spdk_trace
spdk_trace的参数可分为两类，一类是关于指定要分析的trace文件，另一类是定义显示内容。指定trace文件可以直接使用”-f”参数, 后接某个trace文件的路径；也可根据当前SPDK应用名称及进程号，让spdk_trace按照默认规则去目录”/dev/shm”下寻找对应的trace文件。很多情况下，SPDK应用运行在不止一个CPU core上，而且IO通常是由一个CPU core 运行到完成(run-to-completion)，所以为了减少trace分析的记录输出量，可以使用”-c”参数指定仅仅分析某一个CPU core上的trace 记录。
Spdk_trace根据事件的不同，每个事件的输出内容会略有不同。从左到右大致的格式遵循：
1 <CPU Index>
2 <Event Occur Time in us>
3 <Group Type Prefix>+<Poller ID>
4 <Specific Type Info>
5 <Event ID>
6 <Completion Time in us>
例如一个Core 0上Bdev IO的开始与结束的输出：
Figure3 Output of spdk_trace for bdev IO
4
Hands-on SPDK trace
这里用SPDK Bdev的一个测试应用 bdev_svc(位于test/app/bdev_svc/), 简要运行一个tracing Bdev IO的例程。
1.启动bdev_svc， 并获取其进程ID
./test/app/bdev_svc/bdev_svc
2.使能Bdev的tracing
./scripts/rpc.py enable_tpoint_group bdev
3.创建基于内存的Bdev
./scripts/rpc.py bdev_malloc_create -b TestBdev 1024 4096
4.将该Bdev 导出为Kernel的NBD设备，并向Bdev发起IO请求
./scripts/rpc.py start_nbd_disk TestBdev /dev/nbd0
fdisk -l /dev/nbd0
./scripts/rpc.py stop_nbd_disk /dev/nbd0
5.查看产生的trace记录
./app/trace/spdk_trace -s bdev_svc -p 72791
Figure4 SPDK trace sample output
6.查看Core 1上的trace记录，可以看到Core0上没有任何event。（因为NBD仅仅运行在Master Core， 即Core 0上）
./app/trace/spdk_trace -s bdev_svc -p 72791 –c 1
7.查看Core 0上的trace记录
./app/trace/spdk_trace -s bdev_svc -p 72791 –c 0
可以看到SPDK trace记录了NBD 的发起IO。每个IO都被唯一标识，由于Bdev目前仅仅设置了两个事件，即BDEV_IO_START和BDEV_IO_END；而且仅仅Bdev的tracing功能被开启， 所以此例程里，记录事件的类型仅有这两种。在SPDK 的NVMe over RDMA, NVMe over TCP, FTL以及ISCSI和Blobfs里面都有更丰富的事件类型。在SPDK网址的documentation中有关于NVMe over RDMA Target的一些trace细节，可参考https://spdk.io/doc/nvmf_tgt_tracepoints.html