ns-3 入门 3:日志、命令参数和跟踪

根据官方教程 Tweaking 一章写成。

日志

ns-3 自带一个日志系统。用日志系统记录输出和错误等是常见的做法,但由于追踪系统的存在(可以使用 tcpdump 或者 Wireshark 看),日志系统还是用来记录错误和调试信息为主。

前面讲到 ns-3 的日志系统粒度为模块,可以对某个模块启用、禁用、设置级别等。

日志级别

日志系统有以下几个级别:

  • LOG_ERROR:错误
  • LOG_WARN:警告
  • LOG_DEBUG:临时的调试信息
  • LOG_INFO:程序运行进度等信息
  • LOG_FUNCTION:函数调用信息
  • LOG_LOGIC:函数内部的逻辑执行
  • LOG_ALL:包含以上所有

LOG_FUNCTION 等级会在每个函数执行时打印信息,比如下面这样。

log
UdpEchoClientApplication:UdpEchoClient(0xef90d0)
UdpEchoClientApplication:SetDataSize(0xef90d0, 1024)
UdpEchoClientApplication:StartApplication(0xef90d0)
UdpEchoClientApplication:ScheduleTransmit(0xef90d0, +0ns)
UdpEchoClientApplication:Send(0xef90d0)

需要注意以上每种日志级别仅包含其本身。若要包含上级日志,则可使用对应的 LOG_LEVEL。如 LOG_LEVEL_DEBUGLOG_ERRORLOG_WARNLOG_DEBUG 三者的并集,皆会打印。

另外还有一种 LOG_UNCOND 级别,会打印任何日志条目,无视等级。

设置级别

有两种办法对模块日志级别进行设置:环境变量和代码。环境变量设置不需要重新编译,所以比较方便。官方教程提到可以用环境变量“提高日志记录级别”,实际测试发现最终输出的日志范围是对两者取并集(包括下文的日志前缀部分)。

如果使用代码,需要使用 LogComponentEnable 函数,若要设置多个模块的日志级别,多次调用该函数即可。比如将 UdpEchoClientApplication 的日志级别设为 INFO

cpp
1
LogComponentEnable("UdpEchoClientApplication", LOG_LEVEL_INFO);

如果只想要启用某个模块的自定义等级日志,可以使用并运算:

cpp
1
LogComponentEnable("UdpEchoClientApplication", LogLevel(LOG_INFO | LOG_FUNCTION));

而控制日志级别的环境变量是 NS_LOG,虽然只有一个变量,但使用和 PATH 类似的表示方法,也可以控制多个模块的级别,其值的格式为 Component1=level_1:Component2=level_2。比如:

bash
1
export NS_LOG="UdpEchoClientApplication=level_all:UdpEchoServerApplication=level_all"

环境变量表示的并运算会更加直观些:

bash
1
export NS_LOG="UdpEchoClientApplication=level_info|level_function"

如果需要设置所有模块的日志级别,可以将 * 作为 Component 的值。需注意该选项会导致大量输出。

日志前缀

回想第一个示例代码的输出,前面的日志输出的几乎都只有内容。比如之前那个示例程序,在启用所有日志等级时,输出是这样的:

log
UdpEchoServerApplication:UdpEchoServer(0x55fd771b1b10)
UdpEchoClientApplication:UdpEchoClient(0x55fd771d9570)
UdpEchoClientApplication:SetDataSize(0x55fd771d9570, 1024)
UdpEchoServerApplication:StartApplication(0x55fd771b1b10)
UdpEchoClientApplication:StartApplication(0x55fd771d9570)
UdpEchoClientApplication:ScheduleTransmit(0x55fd771d9570, +0ns)
UdpEchoClientApplication:Send(0x55fd771d9570)
At time +2s client sent 1024 bytes to 10.1.1.2 port 9
UdpEchoServerApplication:HandleRead(0x55fd771b1b10, 0x55fd771e5e70)
At time +2.00369s server received 1024 bytes from 10.1.1.1 port 49153
Echoing packet
......

日志前缀内容可以和日志输出等级一起设定,目前有如下几个选项1

  • PREFIX_FUNC: 函数名(格式为 ComponentName:FunctionName
  • PREFIX_TIME:仿真已进行的时长
  • PREFIX_NODE:节点编号(就是之前关键抽象中的那个节点)
  • PREFIX_LEVEL:日志等级

也可以用 PREFIX_ALL 一次性打开所有前缀。以使用代码的方式为例,可以这样设置:

cpp
1
2
3
4
    LogComponentEnable("UdpEchoClientApplication",
                       LogLevel(ns3::LOG_LEVEL_ALL | ns3::LOG_PREFIX_ALL));
    LogComponentEnable("UdpEchoServerApplication",
                       LogLevel(ns3::LOG_LEVEL_ALL | ns3::LOG_PREFIX_ALL));

输出便成了这样:

log
+0.000000000s -1 UdpEchoServerApplication:UdpEchoServer(0x55b8911fcb10)
+0.000000000s -1 UdpEchoClientApplication:UdpEchoClient(0x55b891224570)
+0.000000000s -1 UdpEchoClientApplication:SetDataSize(0x55b891224570, 1024)
+1.000000000s 1 UdpEchoServerApplication:StartApplication(0x55b8911fcb10)
+2.000000000s 0 UdpEchoClientApplication:StartApplication(0x55b891224570)
+2.000000000s 0 UdpEchoClientApplication:ScheduleTransmit(0x55b891224570, +0ns)
+2.000000000s 0 UdpEchoClientApplication:Send(0x55b891224570)
+2.000000000s 0 UdpEchoClientApplication:Send(): [INFO ] At time +2s client sent 1024 bytes to 10.1.1.2 port 9
+2.003686400s 1 UdpEchoServerApplication:HandleRead(0x55b8911fcb10, 0x55b891230e70)
+2.003686400s 1 UdpEchoServerApplication:HandleRead(): [INFO ] At time +2.00369s server received 1024 bytes from 10.1.1.1 port 49153
+2.003686400s 1 UdpEchoServerApplication:HandleRead(): [LOGIC] Echoing packet
......

记录日志

要将某个源文件划入某个模块,可以使用这个宏:

cpp
1
NS_LOG_COMPONENT_DEFINE("ComponentName");

对于 LOG_FUNCTION 级别的日志,可以使用 NS_LOG_FUNCTION(this)(静态函数使用 NS_LOG_FUNCTION_NOARGS()),它会在函数开始时打印函数名和参数,函数结束时打印函数名和返回值。而对于其他级别的日志,可以使用 NS_LOG_<LEVEL>,如:

cpp
1
2
NS_LOG_INFO("This is an info message");
NS_LOG_DEBUG("This is a debug message");

命令参数

ns-3 也有一个自带的命令行参数解析器,从而避免手动解析或使用第三方库的麻烦。在 main 函数传入了 argcargv 的情况下,可以使用 CommandLine 类来解析命令行参数:

cpp
1
2
CommandLine cmd;
cmd.Parse(argc, argv);

要使用 ns3 工具运行时加入命令行参数,可以用下面两种等效的方式:

bash
1
2
./ns3 run examples/tutorial/first.cc -- --PrintHelp
./ns3 run "examples/tutorial/first.cc --PrintHelp"

当然直接加参数也问题不大,会提示更正的。

自带参数

这个参数解析器自带了一些参数,可以通过 --PrintHelp 查看(竟然不是 --help,奇怪)。比如 --PrintAttributes=<TypeId> 可以查看某一类型附带的参数,以及各自的默认值。比如在第一个示例代码中,PointToPointChannel 的默认参数为:

bash
1
2
3
4
5
6
7
$ ./ns3 run examples/tutorial/first.cc -- --PrintAttributes=ns3::PointToPointChannel
Attributes for TypeId ns3::PointToPointChannel
    --ns3::PointToPointChannel::Delay=[+0ns]
        Propagation delay through the channel
Attributes defined in parent class ns3::Channel
    --ns3::Channel::Id=[0]
        The id (unique integer) of this Channel.

这个和我们在文档中看到的是一致的,默认增加 0ns 的延迟,但在代码中增加了 2ms,覆盖了默认值。但--PrintHelp 并没有提到的是,也可以用命令行参数改变这些默认值。比如,在删除代码中设置链路延迟的部分之后,可以使用以下参数将其值改为 100ms:

bash
1
./ns3 run examples/tutorial/first.cc -- --ns3::PointToPointChannel::Delay=100ms

上面“改变默认值”可以理解为:对于一个属性值,设定的优先级为代码设定值>命令行参数设定值>默认值。更高的优先级会完全覆盖低优先级的值。

自定义参数

当然也可以引入自定义的参数,通过 cmd.AddValue 添加。比如在第一个示例代码中,添加一个 --nPackets 参数,用于设置发送的数据包数量:

cpp
1
2
uint32_t nPackets = 1;
cmd.AddValue("nPackets", "Number of packets to send", nPackets);

然后在后面设置 MaxPackets attribute 时传入 nPackets 即可。这样也可以避开命令行参数优先级的问题。

跟踪

模拟的全部目的是生成输出以供进一步研究,而 ns-3 跟踪系统是实现这一目标的主要机制。

—— ns-3 文档

ns-3 的跟踪功能,我划分为三个部分:

  • 跟踪源 (trace source):在仿真的某些阶段触发,并发送某些内部数据(如数据包内容)
  • 跟踪接收器 (trace sink):接收跟踪源发出的数据
  • 前两者之间的连接

将跟踪源和跟踪接收器分开,可以在不改变跟踪源的情况下,更改接收方式(如新增一个接收器)。在这篇开发者给出的教程中,将会使用一些自带的跟踪源和接收器;后面开发者还写了一篇更加详细的教程,以介绍更加复杂的跟踪用法。

ASCII 跟踪

ns-3 自带一个 ASCII 跟踪的 helper 以帮助设置,在前面第一个示例代码中,可以像这样修改:

cpp
1
2
3
AsciiTraceHelper ascii;
pointToPoint.EnableAsciiAll(ascii.CreateFileStream("myfirst.tr"));
Simulator::Run();

然后重新运行一遍,你就会在 shell 的工作目录中看到一个 myfirst.tr 文件。里面有 6 行一长串数据,我们拿出第一行,进行一下换行拆分:

plaintext
1
2
3
4
5
6
7
+ 
2 
/NodeList/0/DeviceList/0/$ns3::PointToPointNetDevice/TxQueue/Enqueue 
ns3::PppHeader (Point-to-Point Protocol: IP (0x0021)) 
ns3::Ipv4Header (tos 0x0 DSCP Default ECN Not-ECT ttl 64 id 0 protocol 17 offset (bytes) 0 flags [none] length: 1052 10.1.1.1 > 10.1.1.2) 
ns3::UdpHeader (length: 1032 49153 > 9) 
Payload (size=1024)

第一行的 + 代表入队操作。每条跟踪数据的第一个字符会有四种可能:

  • +:设备队列上入队
  • -:设备队列上出队
  • d:丢包(dropped),可能是因为队列满了
  • r:从外部接收

第二行的 2 代表模拟进行时刻。第三行描述了该行为的发起者,即节点 0 上的设备 0 发送队列进行入队,也就是节点 0 准备发送数据了。后面的几行可以参照 Internet 的分层模型,分别是链路层的 PPP 头、网络层的 IPv4 头、传输层的 UDP 头和应用层的数据。

PCAP 跟踪

PCAP 相对上面的 ASCII 来说就友好多了,毕竟我们可以用 Wireshark 打开。类似于 ASCII 跟踪,PCAP 跟踪可以这样应用于第一个示例代码:

cpp
1
2
pointToPoint.EnablePcapAll("myfirst");
Simulator::Run();

这次会在 shell 的工作目录下,对每个节点和网络设备生成一个 pcap 文件。tcpdump 的用法这里就不介绍了,Wireshark 则可以直接打开,就像用它抓的包一样。