全部博文（180）
分类： 系统运维
2010-08-05 19:58:20
【致谢】： 感谢关注NS3 Tutorial中文版的广大网友们，感谢NS3翻译小组，感谢初稿的翻译者们，感谢审稿和编辑们！！！ （详细的名单请查看博文翻译Tutorial）
声明：引用和转载相关内容，请尊重作者、翻译者和审稿者的辛勤付出，我们坚信开源的思想，我们希望自己的工作可以为更多的人提供帮助，我们不希望成为随意粘贴和任意复制的对象。
（点击以下目录，可以查看相应的英文原文）
5 Tweaking NS3 （NS3调整？）
|
翻译： 杨飞 |
|
|
校稿： Xiaochuan Shen |
|
|
编辑： ProbibidoAmor |
|
5.1 日志模块的使用
在运行first.cc脚本时，我们已经简单的了解了日志模块。现在，我们将更深入的了解日志子系统是为哪些用户案例设计的。
5.1.1 日志概述
很多大型系统支持某种的消息日志功能，ns3也不例外。在某些情况下，只是错误消息日志被记录到操作控制台(在基于Unix-系统中通常是标准错误输出)。在其他系统中，警告消息可能跟详细的信息消息一起被输出。某些情况下，日志功能被用来输出令人费解的调试信息。
在NS-3中，我们认为这些不同详尽级别的日志都是非常有用的。Ns3还提供了一个可供选择的、多级别的方法来记录日志。日志可以完全被禁用，或仅对部分组件可用，或全局可用。并且ns3提供了不同详尽程度的日志级别供选。NS-3日志模块提供了直观的、相对简单的使用方法来帮助用户获得仿真过程的所需信息。
应当了解我们也提供了一个一般性的记录机制，tracing，来获得仿真结果之外的数据(详情参见本教程的tracing系统的使用章节)。日志应当作为快速获得你的脚本和模型的调试信息、警告信息、错误信息、或是其他信息的首要选择。
在现有的系统中，有7个详尽程度递增的日志级别，他们分别是：
· NS_LOG_ERROR — Log error messages;
· NS_LOG_WARN — Log warning messages;
· NS_LOG_DEBUG — Log relatively rare, ad-hoc debugging messages;
· NS_LOG_INFO — Log informational messages about program progress;
· NS_LOG_FUNCTION — Log a message describing each function called;
· NS_LOG_LOGIC – Log messages describing logical flow within a function;
· NS_LOG_ALL — Log everything.
· NS_LOG_ERROR — 记录错误信息;
· NS_LOG_WARN — 记录警告信息;
· NS_LOG_DEBUG — 记录相对不常见的调试信息;
· NS_LOG_INFO — 记录程序进展信息;
· NS_LOG_FUNCTION — 记录描述每个调用函数信息;
· NS_LOG_LOGIC – 记录一个函数内描述逻辑流程的信息;
· NS_LOG_ALL — 记录所有信息.
我们也提供了一种一直被使用的无条件日志级别，它是跟日志详尽级别或是组件选择无关的。
· NS_LOG_UNCOND – 无条件记录相关消息.
每一个级别能够被单独地被调用或逐级递增的被调用。日志的配置可以使用一个shell环境变量(NS_LOG)，或是使用日志系统函数进行。正如在本教程之前部分看到的，日志系统有Doxygen文档，如果你还没有阅读日志模型文档现在是个好的时机。
既然你已经很详细地阅读了文档，我们使用日志来获得之前建立的first.cc脚本的一些有用信息。
5.1.2 启用日志
我们将使用NS_LOG环境变量来打开一些日志功能。首先，需要耐心点，像之那样运行脚本，
./war --run scratch/myfirst
你应当看到熟悉的、第一个ns-3例子程序的结果
Waf: Entering directory `/home/craigdo/repos/ns-3-allinone/ns-3-dev/build'
Waf: Leaving directory `/home/craigdo/repos/ns-3-allinone/ns-3-dev/build'
'build' finished successfully (0.413s)
Sent 1024 bytes to 10.1.1.2
Received 1024 bytes from 10.1.1.1
Received 1024 bytes from 10.1.1.2
上面看到的"Sent"和"Received"消息实际上是来自UdpEchoClientApplication 和 UdpEchoServerApplication的日志消息。我们通过NS_LOG环境变量设置日志级别让客户端程序输出更多信息。
假设你在使用一个类sh的shell。此类shell使用“VARIABLE=value”的语法格式设置环境变量。如果使用类csh的shell，必须将例句改成"setenv VARIABLE value"语法格式的语句。
现在，scratch/myfirst.cc中UDP回显客户端应用在使用下面的代码行进行响应，
LogComponentEnable("UdpEchoClientApplication", LOG_LEVEL_INFO);
这行代码设置日志为LOG_LEVEL_INFO级别。当我们传递一个日志级别标志时，我们实际上打开了这个日志级别和它之下的所有级别。本例中，我们打开了NS_LOG_INFO, NS_LOG_DEBUG, NS_LOG_WARN 和 NS_LOG_ERROR级别。我们可以通过设置NS_LOG环境变量在不改变脚本或重新编译的情况下来增加日志级别，获得更多信息，
export NS_LOG=UdpEchoClientApplication=level_all
这个设置shell环境变量NS_LOG为字符串：
UdpEchoClientApplication=level_all
等号左边是我们想要设置日志级别的组件的名字，等号右边是我们想要使用的日志级别。本例中，我们要为应用打开所有的调试信息级别。我们把NS_LOG设为这个样子，NS-3日志系统将识别出日志级别改变，输出下面的结果：
Waf: Entering directory `/home/craigdo/repos/ns-3-allinone/ns-3-dev/build
Waf: Leaving directory `/home/craigdo/repos/ns-3-allinone/ns-3-dev/build'
'build' finished successfully (0.404s)
UdpEchoClientApplication:UdpEchoClient()
UdpEchoClientApplication:SetDataSize(1024)
UdpEchoClientApplication:StartApplication()
UdpEchoClientApplication:ScheduleTransmit()
UdpEchoClientApplication:Send()
Sent 1024 bytes to 10.1.1.2
Received 1024 bytes from 10.1.1.1
UdpEchoClientApplication:HandleRead(0x6241e0, 0x624a20)
Received 1024 bytes from 10.1.1.2
UdpEchoClientApplication:StopApplication()
UdpEchoClientApplication:DoDispose()
UdpEchoClientApplication:~UdpEchoClient()
这些额外的调试信息是来自NS_LOG_FUNTION级别的日志。这些信息显示了在脚本运行期间程序中每个函数调用过程。注意，ns-3中模型对日志的支持并不是必须的。有关被记录信息的多少是由模型的开发者决定的。在本例中，有很多日志输出
你可以看到回显客户端程序中调用函数的日志。如果仔细看，会注意到字符串UdpEchoClientApplication和方法名之间是单冒号，而不是你预期的C++域操作符(::)（双冒号）。这里是有意这样做的。
名字UdpEchoClientApplication并非一个类名，而是日志组件名。当一个类仅由一个源文件代表时，这个位置的显示通常是这个类的名字。这里用一个冒号来替代两个冒号，来提醒用户区分日志组件名和类名的细微差别：这个位置显示的是组件名，而并不是类名。
在某些情况下，确定哪个方法生成了某条日志消息是很困难的。如果你看过上面的文档，你或许想知道字符串“Received 1024 bytes from 10.1.1.2”来自哪里。我们可以通过在NS_LOG环境变量中设置prefix_func级别来解决。试着下面的语句做，
export 'NS_LOG=UdpEchoClientApplication=level_all|prefix_func'
注意，这里引号是必须的，因为我们用的竖线表示或操作，而在Unix中竖线表示管道连接。
现在如果运行脚本你将看到每条日志都有产生此条日志的组件名做前缀了。
Waf: Entering directory `/home/craigdo/repos/ns-3-allinone/ns-3-dev/build'
Waf: Leaving directory `/home/craigdo/repos/ns-3-allinone/ns-3-dev/build'
'build' finished successfully (0.417s)
UdpEchoClientApplication:UdpEchoClient()
UdpEchoClientApplication:SetDataSize(1024)
UdpEchoClientApplication:StartApplication()
UdpEchoClientApplication:ScheduleTransmit()
UdpEchoClientApplication:Send()
UdpEchoClientApplication:Send(): Sent 1024 bytes to 10.1.1.2
Received 1024 bytes from 10.1.1.1
UdpEchoClientApplication:HandleRead(0x6241e0, 0x624a20)
UdpEchoClientApplication:HandleRead(): Received 1024 bytes from 10.1.1.2
UdpEchoClientApplication:StopApplication()
UdpEchoClientApplication:DoDispose()
UdpEchoClientApplication:~UdpEchoClient()
你现在看到来自UDP回显客户端程序的消息这样被识别了。消息“Received 1024 bytes from 10.1.1.2”明显来自回显客户端程序。剩下的消息一定是来自UDP回显服务器程序。我们可以通过在NS_LOG环境变量中键入一个单冒号隔开的组件列表来启用回显服务器应用组件。
export 'NS_LOG=UdpEchoClientApplication=level_all|prefix_func:
UdpEchoServerApplication=level_all|prefix_func'
警告：你必须删除单冒号后的换行符，在例子文本中仅仅只是为了编排格式。
现在，如果你运行脚本，你将看到来自回显客户端和服务器的所有日志消息。这对于调试问题很有用。
Waf: Entering directory `/home/craigdo/repos/ns-3-allinone/ns-3-dev/build'
Waf: Leaving directory `/home/craigdo/repos/ns-3-allinone/ns-3-dev/build'
'build' finished successfully (0.406s)
UdpEchoServerApplication:UdpEchoServer()
UdpEchoClientApplication:UdpEchoClient()
UdpEchoClientApplication:SetDataSize(1024)
UdpEchoServerApplication:StartApplication()
UdpEchoClientApplication:StartApplication()
UdpEchoClientApplication:ScheduleTransmit()
UdpEchoClientApplication:Send()
UdpEchoClientApplication:Send(): Sent 1024 bytes to 10.1.1.2
UdpEchoServerApplication:HandleRead(): Received 1024 bytes from 10.1.1.1
UdpEchoServerApplication:HandleRead(): Echoing packet
UdpEchoClientApplication:HandleRead(0x624920, 0x625160)
UdpEchoClientApplication:HandleRead(): Received 1024 bytes from 10.1.1.2
UdpEchoServerApplication:StopApplication()
UdpEchoClientApplication:StopApplication()
UdpEchoClientApplication:DoDispose()
UdpEchoServerApplication:DoDispose()
UdpEchoClientApplication:~UdpEchoClient()
UdpEchoServerApplication:~UdpEchoServer()
有时能够看到日志生成的仿真时间也是很有用的。可以通过使用prefix_time位来实现。
export 'NS_LOG=UdpEchoClientApplication=level_all|prefix_func|prefix_time:
UdpEchoServerApplication=level_all|prefix_func|prefix_time'
输入时你必须先移除上面的换行符。如果你现在运行此脚本，你将看到下面的结果：
Waf: Entering directory `/home/craigdo/repos/ns-3-allinone/ns-3-dev/build'
Waf: Leaving directory `/home/craigdo/repos/ns-3-allinone/ns-3-dev/build'
'build' finished successfully (0.418s)
0s UdpEchoServerApplication:UdpEchoServer()
0s UdpEchoClientApplication:UdpEchoClient()
0s UdpEchoClientApplication:SetDataSize(1024)
1s UdpEchoServerApplication:StartApplication()
2s UdpEchoClientApplication:StartApplication()
2s UdpEchoClientApplication:ScheduleTransmit()
2s UdpEchoClientApplication:Send()
2s UdpEchoClientApplication:Send(): Sent 1024 bytes to 10.1.1.2
2.00369s UdpEchoServerApplication:HandleRead(): Received 1024 bytes from 10.1.1.1
2.00369s UdpEchoServerApplication:HandleRead(): Echoing packet
2.00737s UdpEchoClientApplication:HandleRead(0x624290, 0x624ad0)
2.00737s UdpEchoClientApplication:HandleRead(): Received 1024 bytes from 10.1.1.2
10s UdpEchoServerApplication:StopApplication()
10s UdpEchoClientApplication:StopApplication()
UdpEchoClientApplication:DoDispose()
UdpEchoServerApplication:DoDispose()
UdpEchoClientApplication:~UdpEchoClient()
UdpEchoServerApplication:~UdpEchoServer()
可以看到UdpEchoServer的构造函数在仿真的第0秒被调用。事实上这实在仿真开始之前就完成了，但时间显示的是0秒。UdpEchoClient的构造函数也是一样。
回忆在scratch/first.cc脚本中，1秒时启动回显服务器应用。可以看到服务器的StartApplication实际上是在1秒时被调用。同样，客户端响应程序正如我们所预料的在仿真2秒时开始。
我们现在可以看到仿真的进度了，我们可以看到从ScheduleTransmit函数在客户端中调用send函数，到回显服务器中调用HandleRead函数的整个过程了。注意到通过点到点连接发送包消耗时间是3.69毫秒。查看回显服务器日志记录了一条消息告诉你已经响应了数据包。在另一个通道延迟后，可以看到响应客户端用它的HandleRead方法收到响应包。
在仿真过程中发生了很多你所没有看到的事情。现在可以很容易的打开系统的日志组件，察看整个过程了。现在试着设置NS_LOG变量为，
export 'NS_LOG=*=level_all|prefix_func|prefix_time'
上面的星号是日志组件通配符。将打开在仿真过程中使用的所有组件的日志功能。这里不列出结果了。可以将这些信息重定向到一个文件，并且用自己喜欢的编辑器打开查看。
./waf --run scratch/myfirst > log.out 2>&1.
当我碰到一个问题或是不知道那里出错了，我使用最详细的日志功能。可以很简单的跟踪程序，而无需设置断点并且在调试器中一步步运行代码。我可以用我喜欢的编辑器来打开查看日至，寻找问题所在。当我对错误有了大致了解之后，我使用调试器对问题有个非常详细的检查。当你脚本做了完全非预期的事，这种输出将是非常有用的。如果你使用调试器单步运行，或许你会错过偏差的部分。日志使得这些偏差非常明显。
5.1.3 为你的代码增加日志功能
可以通过几个宏调用日志组件给仿真增加新的日志功能。我们可以在scratch目录中的myfirst.cc中做。
也许你还记得在脚本中我们已经定义过一个日志组件：
NS_LOG_COMPONENT_DEFINE ("FirstScriptExample");
我们已经了解了通过设置NS_LOG环境变量来给组件启用日志功能。我们可以给脚本增加一些日志功能。用来增加信息级别的日志消息的宏是NS_LOG_
Open scratch/myfirst.cc in your favorite editor and add the line,
用你钟爱的编辑器打开scratch/myfirst.cc文件并且在NodeContainer nodes; nodes.Create(2);之前加上一行，
NS_LOG_INFO ("Creating Topology");
现在用waf编译脚本并且清除NS_LOG环境变量来关掉我们之前启用的日志文件：
./waf
export NS_LOG=
现在，运行脚本，
./waf --run scratch/myfirst
你将不会看到新的日志消息，因为与它相关的日志组件(FirstScriptExample)没有被启用。为了看到你的消息，必须使用大于或等于NS_LOG_
export NS_LOG=FirstScriptExample=info
如果现在运行脚本你将看到新建的"Creating Topology"日志消息，
Waf: Entering directory `/home/craigdo/repos/ns-3-allinone/ns-3-dev/build'
Waf: Leaving directory `/home/craigdo/repos/ns-3-allinone/ns-3-dev/build'
'build' finished successfully (0.404s)
Creating Topology
Sent 1024 bytes to 10.1.1.2
Received 1024 bytes from 10.1.1.1
Received 1024 bytes from 10.1.1.2
