1. LTTng

1.1 安装LTTng

LTTng: (Linux Trace Toolkit Next Generation),它是用于跟踪 Linux 内核、应用程序以及库的系统软件包。
Session守护进程和用户空间跟踪库使用Unix域套接字进行通信 ,
Consumer守护进程总是在创建事件规则后由会话守护进程生成 。
image.png

  1. yum install libuuid-devel popt-devel libxml2-devel \
  2. numactl-devel userspace-rcu-devel glib2-devel -y

ubuntu安装lttng-ust、lttng-tools、babeltrace可以尝试apt-get;
centos8的yum或者不可用,或者没有,已尝试过。

1.1.1 lttng-ust

用于检测和跟踪用户应用程序的库和Java/Python包。

  1. # yum packages (NG)
  2. yum install lttng-ust-devel
  3. yum install libbabeltrace-devel
  4. yum安装成功,但是
  5. 在/usr/include/lttng/ust-config.h中定义了 LTTNG_UST_HAVE_SDT_INTEGRATION
  6. 期望是undef的,所以centos8 yum install后,在msquic cmake时仍然未启用lttng
  7. 直接yum安装不符合msquic要求,接下来从源码中安装,ubuntu等系统未尝试。
  1. # build from source (2.11.5~OK)
  2. mkdir software &&
  3. cd software &&
  4. wget http://lttng.org/files/lttng-ust/lttng-ust-2.11.5.tar.bz2 &&
  5. tar -xf lttng-ust-2.11.5.tar.bz2 &&
  6. cd lttng-ust-2.11.5 &&
  7. ./configure --prefix=/usr &&
  8. make -j4 &&
  9. sudo make install &&
  10. sudo ldconfig

1.1.2 lttng-tools

用于控制跟踪的库和命令行接口。

  1. # build from source (2.11.5~OK)
  2. mkdir software &&
  3. cd software &&
  4. wget http://lttng.org/files/lttng-tools/lttng-tools-2.11.5.tar.bz2 &&
  5. tar -xf lttng-tools-2.11.5.tar.bz2 &&
  6. cd lttng-tools-2.11.5 &&
  7. ./configure --prefix=/usr &&
  8. make -j4 &&
  9. sudo make install &&
  10. sudo ldconfig

1.1.3 babeltrace

Babeltrace是一个命令行工具,它可以转换跟踪格式; 它支持lttng产生的格式,CTF,以及一个基本的文本输出,可以被grep。 babeltrace命令是babeltrace项目的一部分。

  1. mkdir software &&
  2. cd software &&
  3. wget https://www.efficios.com/files/babeltrace/babeltrace2-2.0.3.tar.bz2 &&
  4. tar -xf babeltrace2-2.0.3.tar.bz2 &&
  5. cd babeltrace2-2.0.3 &&
  6. ./configure --prefix=/usr --disable-debug-info &&
  7. make -j4 &&
  8. sudo make install &&
  9. sudo ldconfig

1.2 抓取日志

  1. # 开启lttng会话守护进程
  2. lttng-sessiond --daemonize
  3. # 展示所有session
  4. lttng list
  5. # 展示所有追踪列表
  6. lttng list --userspace
  7. # 展示指定会话列表
  8. lttng list --userspace my-user-space-session
  9. 结果如下:
  10. UST events:
  11. -------------
  12. PID: 222054 - Name: ./quicsample
  13. CLOG_WORKER_C:AllocFailure (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
  14. CLOG_WORKER_C:WorkerStop (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
  15. ......
  16. # 创建自己的会话 (自定义my-user-space-session)
  17. lttng create my-user-space-session
  18. # 创建一个事件
  19. lttng enable-event --userspace --session=my-user-space-session CLOG_STREAM_RECV_C:*
  20. # 开启所有事件
  21. lttng enable-event --userspace --loglevel=TRACE_DEBUG --session=my-user-space-session --all
  22. # 暂停所有事件
  23. lttng disable-event --userspace --session=my-user-space-session --all-events
  24. # 暂停一个事件
  25. lttng disable-event --userspace --session=my-user-space-session CLOG_STREAM_RECV_C:*
  26. # 开启追踪
  27. lttng start
  28. # 关闭追踪
  29. lttng stop
  30. # 删除会话(不会删除数据)
  31. lttng destroy
  32. # 设置当前lttng跟踪会话
  33. lttng set-session my-user-space-session
  34. # 查看当前会话
  35. lttng status
  36. # 存储路径在 $LTTNG_HOME/lttng-traces/name-date-time
  37. # name是会话名字,LTTNG_HOME是环境变量,如果没设置,默认到$HOME

1.3 分析日志

  1. # 无选项(打印到屏幕,可以重定向 > msquic.log)
  2. babeltrace2 ~/lttng-traces/my-user-space-session*
  3. # 增加grep
  4. babeltrace2 /tmp/my-kernel-trace | grep _switch
  5. # 增加wc
  6. babeltrace2 /tmp/my-kernel-trace | grep _open | wc --lines

2. msquic开启日志

2.1 编译

  1. cmake升级到3.6.0及以上版本(centos83.18.2符合要求)
  2. cmake -version查看
  3. 根目录的cmakelist开启QUIC_ENABLE_LOGGING
  4. 增加选项 -DQUIC_ENABLE_LOGGING=ON
  5. 即:
  6. mkdir build &&
  7. cd build &&
  8. cmake -G 'Unix Makefiles' -DCMAKE_INSTALL_PREFIX=/usr \
  9. -DQUIC_TLS_SECRETS_SUPPORT=ON -DCMAKE_BUILD_TYPE=Debug \
  10. -DQUIC_ENABLE_LOGGING=ON ..
  11. make -j4

cmake执行后,确认是否开启日志

  • 失败例子

image.png

  • 成功例子

image.png

  • 说明 ```c

    include

    stream_recv.c.log.h -> stream_recv.c.clog.h.lttng.h

include

  1. <a name="lzzfc"></a>
  2. ## 2.2 抓取/分析日志

msquic与vpp建立连接

./quicsample -client -target:172.16.1.1 -unsecure -user:bob

开启守护进程

lttng-sessiond —daemonize

创建会话 (自定义msquic-session)

lttng create msquic-session

开启所有日志

lttng enable-event —userspace —loglevel=TRACE_DEBUG —session=msquic-session —all

开启追踪

lttng start

发送数据(打流等)

ping 172.16.2.100 -i 2

关闭追踪

lttng stop

无选项

babeltrace2 ~/lttng-traces/msquic-session* > ~/lttng-traces/msquic.log

  1. [msquic_trace_func.txt](https://www.yuque.com/attachments/yuque/0/2022/txt/12487488/1650876711775-fb5bf4b2-8037-401c-90cd-a7bf969ea087.txt?_lake_card=%7B%22src%22%3A%22https%3A%2F%2Fwww.yuque.com%2Fattachments%2Fyuque%2F0%2F2022%2Ftxt%2F12487488%2F1650876711775-fb5bf4b2-8037-401c-90cd-a7bf969ea087.txt%22%2C%22name%22%3A%22msquic_trace_func.txt%22%2C%22size%22%3A77919%2C%22type%22%3A%22text%2Fplain%22%2C%22ext%22%3A%22txt%22%2C%22source%22%3A%22%22%2C%22status%22%3A%22done%22%2C%22mode%22%3A%22title%22%2C%22download%22%3Atrue%2C%22taskId%22%3A%22u42cf8f2d-be04-4ef8-a2c5-d3f31bda784%22%2C%22taskType%22%3A%22upload%22%2C%22id%22%3A%22u5992050b%22%2C%22card%22%3A%22file%22%7D)<br />[start_lttng.sh](https://www.yuque.com/attachments/yuque/0/2022/sh/12487488/1654680921686-dfa0ef5e-1816-42a6-b071-0bf7e909df00.sh?_lake_card=%7B%22src%22%3A%22https%3A%2F%2Fwww.yuque.com%2Fattachments%2Fyuque%2F0%2F2022%2Fsh%2F12487488%2F1654680921686-dfa0ef5e-1816-42a6-b071-0bf7e909df00.sh%22%2C%22name%22%3A%22start_lttng.sh%22%2C%22size%22%3A196%2C%22type%22%3A%22text%2Fx-sh%22%2C%22ext%22%3A%22sh%22%2C%22source%22%3A%22%22%2C%22status%22%3A%22done%22%2C%22mode%22%3A%22title%22%2C%22download%22%3Atrue%2C%22taskId%22%3A%22uc1eeb70c-3c97-432a-abf3-b6e684a3a69%22%2C%22taskType%22%3A%22upload%22%2C%22__spacing%22%3A%22both%22%2C%22id%22%3A%22u334104be%22%2C%22margin%22%3A%7B%22top%22%3Atrue%2C%22bottom%22%3Atrue%7D%2C%22card%22%3A%22file%22%7D)
  2. <a name="INIee"></a>
  3. ## 2.3 查询
  4. <a name="bJ7t7"></a>
  5. ### 2.3.1 lttng list

lttng list

  1. <a name="Qc6VN"></a>
  2. ### ![所有会话.png](https://cdn.nlark.com/yuque/0/2022/png/12487488/1650940492051-a3166149-d6ba-48f8-aaac-2e8eec0361a3.png#clientId=u0e78b545-e7f9-4&crop=0&crop=0&crop=1&crop=1&from=drop&id=u23171570&margin=%5Bobject%20Object%5D&name=%E6%89%80%E6%9C%89%E4%BC%9A%E8%AF%9D.png&originHeight=244&originWidth=997&originalType=binary&ratio=1&rotation=0&showTitle=false&size=19682&status=done&style=none&taskId=u0d836f02-20d3-4731-8b36-8ecb8ce9ff9&title=)
  3. <a name="jgufo"></a>
  4. ### <br />2.3.2 lttng list --userspace

lttng list —userspace

  1. ![日志种类.png](https://cdn.nlark.com/yuque/0/2022/png/12487488/1650940513484-0537ecd8-e2b9-4677-8d83-a170f945a03d.png#clientId=u0e78b545-e7f9-4&crop=0&crop=0&crop=1&crop=1&from=drop&id=u6d1aaad3&margin=%5Bobject%20Object%5D&name=%E6%97%A5%E5%BF%97%E7%A7%8D%E7%B1%BB.png&originHeight=701&originWidth=1465&originalType=binary&ratio=1&rotation=0&showTitle=false&size=138443&status=done&style=none&taskId=u5f910d2d-8eaf-499b-9158-6ad13d9a09d&title=)
  2. <a name="zistT"></a>
  3. ### 2.3.3 lttng list --userspace msquic-session

lttng list —userspace msquic-session

  1. ![已添加事件.png](https://cdn.nlark.com/yuque/0/2022/png/12487488/1650940534757-8310eb43-5b64-462c-9833-e2077abb9075.png#clientId=u0e78b545-e7f9-4&crop=0&crop=0&crop=1&crop=1&from=drop&id=u123d4c9c&margin=%5Bobject%20Object%5D&name=%E5%B7%B2%E6%B7%BB%E5%8A%A0%E4%BA%8B%E4%BB%B6.png&originHeight=667&originWidth=1434&originalType=binary&ratio=1&rotation=0&showTitle=false&size=51678&status=done&style=none&taskId=u7c0f1a45-8b97-4524-8b16-d1155d74f08&title=)
  2. <a name="fimeu"></a>
  3. ### 2.3.4 确认需要追踪的日志
  4. <br />以stream_recv.c中的一个事件为例,想要打印Receive的这个日志,那么需要找到stream_recv.c.clog.h.lttng.h文件,确认其在lttng中的名字(即使用lttng list --userspace展示的结果)。
  5. lttng list --userspace中展示的结果如下:<br />![代码与lttng对应关系.png](https://cdn.nlark.com/yuque/0/2022/png/12487488/1650940660489-14830f3f-5b82-4503-994a-f05fcf19c8df.png#clientId=u0e78b545-e7f9-4&crop=0&crop=0&crop=1&crop=1&from=drop&id=ufa3dbef0&margin=%5Bobject%20Object%5D&name=%E4%BB%A3%E7%A0%81%E4%B8%8Elttng%E5%AF%B9%E5%BA%94%E5%85%B3%E7%B3%BB.png&originHeight=840&originWidth=906&originalType=binary&ratio=1&rotation=0&showTitle=false&size=98543&status=done&style=none&taskId=u64163458-4987-4757-acde-4f7b44eadbb&title=)<br />那么执行如下命令后即可添加Receive日志,再抓取、解析后可获得

lttng enable-event —userspace CLOG_STREAM_RECV_C:Receive

  1. ![日志结果.png](https://cdn.nlark.com/yuque/0/2022/png/12487488/1650940669467-58b2f4f6-509e-4a44-9fae-809c962dd355.png#clientId=u0e78b545-e7f9-4&crop=0&crop=0&crop=1&crop=1&from=drop&id=u25da3020&margin=%5Bobject%20Object%5D&name=%E6%97%A5%E5%BF%97%E7%BB%93%E6%9E%9C.png&originHeight=53&originWidth=1551&originalType=binary&ratio=1&rotation=0&showTitle=false&size=9989&status=done&style=none&taskId=udacccc97-1979-4079-a0ec-cbf244c9a93&title=)
  2. <a name="ibFy6"></a>
  3. # 3. ETW
  4. <a name="8f65ddd8"></a>
  5. ## 3.1 抓取日志
  6. 1. 管理员运行cmd,开启日志;

netsh.exe trace start overwrite=yes report=dis correlation=dis traceFile=quic.etl provider={ff15e657-4f26-570e-88ab-0796b258d11c} level=0x5 keywords=0xffffffff

netsh.exe trace start overwrite=yes report=dis correlation=dis traceFile=quic.etl provider={ff15e657-4f26-570e-88ab-0796b258d11c} level=0x5 keywords=0x00000040

  1. ![image.png](https://cdn.nlark.com/yuque/0/2022/png/12487488/1651148457683-f35ed1e4-9c3e-4623-a422-64ed0dd7c496.png#clientId=u8695ff7c-7993-4&crop=0&crop=0&crop=1&crop=1&from=paste&height=519&id=uc47ee7aa&margin=%5Bobject%20Object%5D&name=image.png&originHeight=519&originWidth=899&originalType=binary&ratio=1&rotation=0&showTitle=false&size=55247&status=done&style=none&taskId=u5ff9486c-7488-44ea-bfbb-98cd74b1c76&title=&width=899)<br />
  2. 2. 开启日志后,运行quicsample程序;
  3. 2. 日志抓取完成后,关闭抓取;

netsh.exe trace stop

  1. <br />产生quic.etl文件在quicsample.exe路径,即C:\Program Files (x86)\eversec\quic\quic-client路径,quic.etl是解析前的日志文件,相当于加密的文件。
  2. <a name="497f0bfa"></a>
  3. ## 3.2 解析日志
  4. 使用msquic项目src/manifest/MsQuicEtw.man作为解析参考,可拷贝到exe路径。

wevtutil.exe um “C:\Program Files (x86)\eversec\quic\quic-client\MsQuicEtw.man” wevtutil.exe im “C:\Program Files (x86)\eversec\quic\quic-client\MsQuicEtw.man” /rf:”C:\Program Files (x86)\eversec\quic\quic-client\msquic.dll” /mf:”C:\Program Files (x86)\eversec\quic\quic-client\msquic.dll”

netsh.exe trace convert quic.etl overwrite=yes

  1. <br />产生quic.txt文件在quicsample.exe路径,quic.txt文件就是解析后的日志文件。<br />![win10日志.png](https://cdn.nlark.com/yuque/0/2022/png/12487488/1651148299988-eebd64e0-e8b2-44d6-8c32-4a357871d606.png#clientId=u8695ff7c-7993-4&crop=0&crop=0&crop=1&crop=1&from=drop&id=u30a4c1fd&margin=%5Bobject%20Object%5D&name=win10%E6%97%A5%E5%BF%97.png&originHeight=587&originWidth=1297&originalType=binary&ratio=1&rotation=0&showTitle=false&size=101487&status=done&style=none&taskId=uf796e9f5-e4a7-482d-af97-259cde6219e&title=)
  2. <a name="Vo2S8"></a>
  3. # 4. msquic实例分析
  4. ```c
  5. # 收发包
  6. ConnPacketRecv|ConnPacketSent
  7. # 操作情况
  8. ConnExecOper|ConnExecApiOper|ConnExecTimerOper
  9. # windows收发包
  10. FLUSH_RECV|FLUSH_SEND|Sending batch

4.1 收包

  • 大小 :::info CLOG_DATAPATH_EPOLL_C: DatapathRecv: { cpu_id = 0 }, { arg2 = 0x24D2EE0, arg3 = 1412, arg4 = 1412, arg5_len = 28。。。。。。

// arg2 = arg2 = SocketContext->Binding
// arg3 = arg3 = (uint32_t)RecvPacket->BufferLength
// arg4 = arg4 = (uint32_t)RecvPacket->BufferLength
// arg5 = arg5 = CASTED_CLOG_BYTEARRAY(sizeof(LocalAddr), LocalAddr)
// arg6 = arg6 = CASTED_CLOG_BYTEARRAY(sizeof(
RemoteAddr), RemoteAddr) :::

socket收包信息

  • 数量 :::info CLOG_CONNECTION_C: QueueDatagrams: { cpu_id = 0 }, { arg1 = 0x7F98380010C0, arg3 = 3 }

// arg1 = arg1 = Connection
// arg3 = arg3 = DatagramChainLength :::

记录recv的个数,与上面日志一起

  • 大小 :::info CLOG_CONNECTION_C: ConnPacketRecv: { cpu_id = 2 }, { arg2 = 0x7EFFD4001DE0, arg3 = 12, arg4 = 5, arg5 = 47 }

// arg2 = arg2 = Connection
// arg3 = arg3 = Packet->PacketNumber
// arg4 = arg4 = Packet->IsShortHeader ? QUIC_TRACE_PACKET_ONE_RTT : (Packet->LH->Type + 1)
// arg5 = arg5 = Packet->HeaderLength + Packet->PayloadLength :::

每个conn收到的包

4.2 发包

  • 大小 :::info CLOG_PACKET_BUILDER_C: ConnPacketSent: { cpu_id = 3 }, { arg2 = 0x7FFB30001130, arg3 = 3, arg4 = 5, arg5 = 1220 }

// arg2 = arg2 = Connection
// arg3 = arg3 = Builder->Metadata->PacketNumber
// arg4 = arg4 = QuicPacketTraceType(Builder->Metadata)
// arg5 = arg5 = Builder->Metadata->PacketLength :::

每个conn发送的包

  • 数量 :::info CLOG_PACKET_BUILDER_C: PacketBuilderSendBatch: { cpu_id = 3 }, { arg1 = 0x7F98380010C0, arg3 = 1 }

// arg1 = arg1 = Builder->Connection
// arg3 = arg3 = (uint16_t)Builder->TotalCountDatagrams :::

记录socket发送个数

4.3 操作

  • 操作 :::info CLOG_OPERATION_H:ConnExecOper: { cpu_id = 2 }, { arg2 = 0x7F7A5C001DE0, arg3 = 1 }

// arg2 = arg2 = Connection
// arg3 = arg3 = Oper->Type :::

  • api操作 :::info CLOG_OPERATION_H:ConnExecApiOper: { cpu_id = 2 }, { arg2 = 0x7F7A5C001DE0, arg3 = 3 }

// arg2 = arg2 = Connection
// arg3 = arg3 = Oper->API_CALL.Context->Type :::

  • timer操作 :::info CLOG_OPERATION_H:ConnExecTimerOper: { cpu_id = 2 }, { arg2 = 0x7F7A5C001DE0, arg3 = 1 }

// arg2 = arg2 = Connection
// arg3 = arg3 = Oper->TIMER_EXPIRED.Type :::

5. 参考文献

官方安装/使用-2.11
官方lttng命令行
官方lttng-ust下载
官方lttng-tools下载
官方ETW说明