ns3 Tutorial 中的日誌模塊（翻譯）

時間 2019-12-01

標籤 ns3 tutorial 日誌模塊翻譯简体版

原文原文鏈接

轉載地址：http://blog.sina.com.cn/s/blog_8ecca79b0101d7fe.html

1 日誌模塊的使用

在運行 first.cc 腳本時，咱們已經簡單瞭解了日誌模塊。如今，咱們將更深刻地瞭解日誌子系統是爲哪些用戶案例設計的。

1.1 日誌概述

不少大型系統支持某種消息記錄功能，ns3 也不例外。在某些狀況下，只有錯誤消息會被記錄到操做控制檯（在基於 Unix 的系統中一般是標準錯誤輸出）。在其餘系統中，警告消息可能跟詳細的信息消息一塊兒被輸出。在某些狀況下，日誌功能被用來輸出使人費解的調試信息。

在 NS-3 中，咱們認爲這些不一樣詳盡級別的日誌都是很是有用的。ns3 還提供了一個可供選擇的、多級別的方法來記錄日誌。日誌能夠徹底被禁用，或僅對部分組件可用，或全局可用。而且 ns3 提供了不一樣詳盡程度的日誌級別供選。NS-3 日誌模塊提供了直觀的、相對簡單的使用方法來幫助用戶得到仿真過程的所需信息。

應當瞭解的是，咱們也提供了一個通常性的記錄機制——tracing，來得到仿真結果以外的數據（要獲取更多 tracing 系統的知識，參見 tutorial 的章節「 Using the Tracing System」）。日誌應看成爲快速得到你的腳本和模型的調試信息、警告信息、錯誤信息、或是其餘信息的首要選擇。

在現有的系統中，有7個詳盡程度遞增的日誌級別，這些級別對應的宏從低到高排列爲：

LOG_ERROR — Log error messages （相關的宏：NS_LOG_ERROR）；
LOG_WARN — Log warning messages （相關的宏： NS_LOG_WARN）；
LOG_DEBUG — Log relatively rare, ad-hoc debugging messages （相關的宏： NS_LOG_DEBUG）；
LOG_INFO — Log informational messages about program progress（相關的宏： NS_LOG_INFO）；
LOG_FUNCTION — Log a message describing each function called（兩個相關的宏： NS_LOG_FUNCTION 用於成員函數， NS_LOG_FUNCTION_NOARGS 用於靜態函數）；
LOG_LOGIC – Log messages describing logical flow within a function （相關的宏： NS_LOG_LOGIC）；
LOG_ALL — Log everything mentioned above（無相關的宏）。

咱們也提供了一種一直被使用的無條件日誌級別，它跟日誌詳盡級別和組件選擇無關。

NS_LOG_UNCOND – Log the associated message unconditionally（沒有相關日誌級別）

每個級別可以被單獨地被調用或逐級遞增的被調用。日誌的配置可使用一個 shell 環境變量（NS_LOG），或是使用日誌系統函數進行。正如在本教程以前部分看到的，日誌系統有 Doxygen 文檔，若是你尚未閱讀日誌模型文檔如今是個好的時機。既然你已經很詳細地閱讀了文檔，咱們使用日誌來得到以前創建的 first.cc 腳本的一些有用信息。

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 環境變量設置日誌級別讓客戶端程序輸出更多信息。html

假設你在使用一個類 sh 的 shell。此類 shell 使用「VARIABLE=value」的語法格式設置環境變量。若是使用類 csh 的 shell，必須將例句改爲 "setenv VARIABLE value" 語法格式的語句。node

如今，scratch/myfirst.cc 中 UDP 回顯客戶端應用在使用下面的代碼行進行響應，shell

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

就我的而言，當我碰到一個問題或是不知道那裏出錯了，我會使用最詳細的日誌功能。能夠很簡單的跟蹤程序，而無需設置斷點而且在調試器中一步步運行代碼。我能夠用我喜歡的編輯器來打開查看日誌，尋找問題所在。當我對錯誤有了大體瞭解以後，我會使用調試器對問題進行很是詳細的檢查。當你的腳本作了徹底非預期的事情時，這種輸出將是很是有用的。若是你使用調試器單步運行，或許你會錯過誤差的部分，而日誌使得這些誤差很是明顯。

1.3 爲你的代碼增長日誌功能

能夠經過幾個宏調用日誌組件給仿真增長新的日誌功能。咱們能夠在scratch目錄中的myfirst.cc中實現這一點。

也許你還記得在腳本中咱們已經定義過一個日誌組件：

NS_LOG_COMPONENT_DEFINE ("FirstScriptExample");

咱們已經瞭解了經過設置 NS_LOG 環境變量來給組件啓用日誌功能。咱們能夠給腳本增長一些日誌功能。用來增長信息級別的日誌消息的宏是 NS_LOG_INFO。如今咱們來增長一行顯示本腳本在建立拓撲的語句。此操做是在經過下代碼段完成的。

用你鍾愛的編輯器打開 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_INFO 的日誌級別來啓用 FirstScriptExample 日誌組件。若是隻是想要看某個級別的日誌，你能夠經過下面的語句來啓用它，

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