本日內容

• 如何印 Log?
• 縮排! 讓訊息更好懂!
• 加入 Contexts
• 檢查狀態
• 加上顏色!
• 追蹤變數
• Debug Build Performance
• 預告

連結: Day 7 - Colab

如何印 Log?

在寫 CMakeLists.txt 時, 難免會需要確認變數的數值, 流程是否正確等
這時候我們可以用 message() 來印出訊息, 追蹤程式內部的狀態

message([mode] msg1 [msg2]...)

• mode
  • Log level, 會在下面介紹
• msg#
  • 要印的訊息

就是這麼簡單, 只需要額外注意 log level 就好
所以, 讓我們來看看 CMake 提供了哪些 log level

Log Level

以下先列出常用的 mode, 並依照嚴重程度由高到低排序

• FATAL_ERROR
  • 立即程式終止
• WARNING
  • 不會終止程式
• DEPRECATION
  • 根據變數有不同行為
    • CMAKE_ERROR_DEPRECATED
      • true 時相當於 FATAL_ERROR
    • CMAKE_WARNING_DEPRECATED
      • true 時相當於 WARNING
  • 都沒設的話, CMake 3.5 前不會印
• STATUS
  • 通常是印 整個程式的狀態
• VERBOSE
  • 通常用來印 處理進度, 比整個程式的狀態更細節一點
• DEBUG
  • 實作細節相關的 log, 給我們 (CMakeLists.txt 作者) 看的
• TRACE
  • 開發時 debug 用, 不建議進 code

STATUS 等級以下都是輸出到 stdout, 其他都是輸出到 stderr

而如果沒有 filter log level 的話, CMake 預設會印的 log 是 STATUS 以上

其他不建議用的 Log Level

• SEND_ERROR
  • configure 階段結束後停止, generate 階段就不會再印了
  • 很讓人困惑, 所以不建議用
• AUTHOR_WARNING
  • 不建議用
  • 通常是 CMake 自己內部實做使用
  • 要打開 developer warnings 才看得到
  • 可以加上 -Wno-dev 來 disable
• NOTICE
  • 不建議用
  • 會輸出到 stderr, 但他的使用情境比較偏 info
    • error message 通常代表有問題, 需要使用者進一步查看
    • 但 NOTICE 偏向 info, 不太符合 error message 情境
    • 感覺像是跟使用者說: "欸我這邊有 error, 你注意一下喔"
      使用者: ???

Filter by log level

我們可以在 CLI 設定 --log-level 決定最小要印的 log level
比如

CMakeLists.txt

cmake_minimum_required(VERSION 3.27)
project(ItHome2023)

message(STATUS "Hello World!")

cmake --log-level=VERBOSE -S <src-dir>

Log level 設為 WARNING 就不會印 STATUS level 的 Hello World!

cmake --log-level=WARNING -S <src-dir>

也可以在設定 cache variable CMAKE_MESSAGE_LOG_LEVEL

cmake -DCMAKE_MESSAGE_LOG_LEVEL=VERBOSE -S <src-dir>

縮排! 讓訊息更好懂!

再來講講如何縮排, 當專案架構有階層存在的時候 (有子資料夾下的檔案要 build), 縮排可以讓我們更清楚找到目標訊息

我們可以用 list(APPEND) 設定 CMAKE_MESSAGE_INDENT

在 function 裡使用尤其重要, 記得我們在 Day 5 看過的 variable scop 嗎? 因為 function 會有自己的 variable scope, 在裡面對 CMAKE_MESSAGE_INDENT 的修改不會影響到外面 scope 的值, 所以很方便

來看個例子

function(foo1)
  list(APPEND CMAKE_MESSAGE_INDENT " ") # 👈
  message("${CMAKE_CURRENT_FUNCTION}")
endfunction()

function(foo2)
  list(APPEND CMAKE_MESSAGE_INDENT " ") # 👈
  message("${CMAKE_CURRENT_FUNCTION}")
  foo1()
endfunction()

function(foo3)
  list(APPEND CMAKE_MESSAGE_INDENT " ") # 👈
  message("${CMAKE_CURRENT_FUNCTION}")
  foo2()
endfunction()

message("Top")
foo1()
foo2()
foo3()

• CMAKE_CURRENT_FUNCTION
  • 會印出目前 function 的名稱

結果如下

Top
  foo1
  foo2
    foo1
  foo3
    foo2
      foo1

下面來看看另一種作法: Message Contexts

加入 Contexts

由 CMAKE_MESSAGE_CONTEXT cache variable 控制
會幫我們在輸出的訊息前加上 [<context>], 在有多個子資料夾或是 modules 的專案特別好用, 可以很快區分出該 log 是來自哪裡

該變數可以透過 CLI 設定, 也可以在 CMakeLists.txt 裡面設定
Note: 建議在專案中最上層的 CMakeLists.txt 的 project() 指令之前設定該變數, 才能夠將 CMake 檢查 compiler 的訊息也加上 context, 比如

CMakeLists.txt

cmake_minimum_required(VERSION 3.27)

list(APPEND CMAKE_MESSAGE_CONTEXT ItHome2023) # 👈
project(ItHome2023)

message("Start")

add_subdirectory(foo)
add_subdirectory(bar)

message("End")

foo/CMakeLists.txt

list(APPEND CMAKE_MESSAGE_CONTEXT foo)
message("foo")

bar/CMakeLists.txt

list(APPEND CMAKE_MESSAGE_CONTEXT bar)
message("bar")

然後執行 cmake 時加上 --log-context 即可

cmake --log-context -S ../src

結果如下

-- [ItHome2023] The C compiler identification is GNU 7.5.0
-- [ItHome2023] The CXX compiler identification is GNU 7.5.0
-- [ItHome2023] Detecting C compiler ABI info
-- [ItHome2023] Detecting C compiler ABI info - done
-- [ItHome2023] Check for working C compiler: /usr/bin/cc - skipped
-- [ItHome2023] Detecting C compile features
-- [ItHome2023] Detecting C compile features - done
-- [ItHome2023] Detecting CXX compiler ABI info
-- [ItHome2023] Detecting CXX compiler ABI info - done
-- [ItHome2023] Check for working CXX compiler: /usr/bin/c++ - skipped
-- [ItHome2023] Detecting CXX compile features
-- [ItHome2023] Detecting CXX compile features - done
[ItHome2023] Start
[ItHome2023.foo] foo
[ItHome2023.bar] bar
[ItHome2023] End
-- Configuring done
-- Generating done

可以看到 foo 和 bar 子資料夾的訊息前面分別加上了 [ItHome2023.foo] 或是 [ItHome2023.bar]
最開始的 Compiler check 也都加上了 [ItHome2023] 的 context
就能更清楚知道訊息是從哪裡來的了, 讚讚

project() 的用途?

雖然還沒有介紹, 但是有玩過前幾天的 Colab 的話, 可以看到每個 CMakeLists.txt 裡面都有用到 project() 這個指令

到目前為止的用法都只有用來命名專案, 但其實當我們使用 project() 指令時, CMake 會幫我們做很多事情, 比如

• 設定各種 cache variables, 有些在 Day 4 有介紹過
  • PROJECT_SOURCE_DIR, <PROJECT-NAME>_SOURCE_DIR
  • PROJECT_BINARY_DIR, <PROJECT-NAME>_BINARY_DIR
  • PROJECT_IS_TOP_LEVEL, <PROJECT-NAME>_IS_TOP_LEVEL
• 檢查當前系統的 compiler 和 linker 是否能用
• etc.

先有這個概念即可, 剩下留待 Day 9, 開始我們的 CMake 專案時再詳細介紹 :)

檢查狀態

如果我們的 CMakeLists.txt 想要 根據指令結果印出不同的訊息
我們可以用 message(checkState)

message(checkState msg1 [msg2]...)

• checkState 包含以下幾個狀態
  • CHECK_START
  • CHECK_PASS
  • CHECK_FAIL

CHECK_PASS 和 CHECK_FAIL 都會先重複 CHECK_START 的訊息, 最後才加上 - <pass-message> 或是 - <fail-message>

來看個範例

function(checkSomething resultVar)
  set(${resultVar} NO PARENT_SCOPE)
endfunction()

# Outer check starts here
message(CHECK_START "Checking things")
list(APPEND CMAKE_MESSAGE_INDENT " ")

message(CHECK_START "Checking support for something")
checkSomething(successVar1)
if(successVar1)
  message(CHECK_PASS "supported")
else()
  message(CHECK_FAIL "not supported")
endif()

list(POP_BACK CMAKE_MESSAGE_INDENT)
if(successVar1 OR successVar2)
  message(CHECK_PASS "ok")
else()
  message(CHECK_FAIL "failed")
endif()

結果如下

-- Checking something
--  Checking...
--  Checking... - not supported
-- Checking something - failed
-- Configuring done
-- Generating done

加上顏色!

這其實是 compiler 的功能, 但是記得我們在 Day 3 提過的, CMake 可以看作是 build tools 的管理工具

所以, CMake 提供了 cache variable CMAKE_COLOR_DIAGNOSTICS, 讓我們可以透過該變數操控 compiler 決定是否要對訊息上色

cmake -DCMAKE_COLOR_DIAGNOSITICS:BOOL=<ON|OFF>  -S <src-dir>

比如我們把 log level 都印一遍

CMakeLists.txt

cmake_minimum_required(VERSION 3.27)
project(ItHome2023)

message(TRACE "trace")
message(DEBUG "debug")
message(VERBOSE "verbose")
message(STATUS "status")
message(WARNING "warning")
message(FATAL_ERROR "fatal error")

然後執行

cmake --log-level=TRACE -DCMAKE_COLOR_DIAGNOSITICS:BOOL=ON  -S ../src

會得到以下結果

同樣的, 如果 compiler 不支援顏色的話就沒有用了

追蹤變數

隨著專案越來越複雜, 變數的值可能會在 configure 的過程中不斷改變
造成 debug 困難, 這時我們就可以用 CMake 提供的 variable_watch() 來揪出有誰動他!

variable_watch(<variable> [<command>])

• varName
  • 要追蹤的 variable
• command
  • 要是 CMake function
  • 會收到以下 arguments
    • variable
      • 變數名稱
    • access
      • 操作類型
        • READ_ACCESS
        • UNKNOWN_READ_ACCESS
        • MODIFIED_ACCESS
        • UNKNOWN_MODIFIED_ACCESS
        • REMOVED_ACCESS
      • UNKNOWN_ 只有在操作未定義的變數才會出現
    • value
      • 變數的值
    • current_list_file
      • 操作該變數的檔案
    • stack
      • 操作該變數過程中參與的所有檔案名稱
      • 最底層是最近的檔案, 即和 current_list_file 相同

通常用 variable_watch(<variable>) 就夠了, 不太會再加上 command
看個範例

CMakeLists.txt

cmake_minimum_required(VERSION 3.27)
project(ItHome2023)

variable_watch(name)

function(Foo name)
  message(STATUS "Hello, ${name}!")
endfunction()

set(name "Eric")

Foo(${name})

然後 configure

cmake -S ../src -B .

會得到結果

CMake Debug Log at CMakeLists.txt:10 (set):
  Variable "name" was accessed using MODIFIED_ACCESS with value "Eric".


CMake Debug Log at CMakeLists.txt:12 (Foo):
  Variable "name" was accessed using READ_ACCESS with value "Eric".


CMake Debug Log at CMakeLists.txt:12 (Foo):
  Variable "name" was accessed using MODIFIED_ACCESS with value "Eric".


CMake Debug Log at CMakeLists.txt:7 (message):
  Variable "name" was accessed using READ_ACCESS with value "Eric".
Call Stack (most recent call first):
  CMakeLists.txt:12 (Foo)


-- Hello, Eric!

可以看到, 我們用了 set(), Foo(), message() 來操作 name 這個 normal variable, 都被抓出來了!
但這個訊息相當占用版面, 所以僅限開發時使用, debug 完記得刪掉@@

Debug Build Performance

如果發現 configure stage 很花時間, 不妨 profiling 一下, 看看誰花最多時間!

可以在執行 cmake 時加上以下 options

• --profiling-output=filename
  • profiling 結果存到 filename
  • 如果 fmt 是用 google-trace, 建議輸出帶上副檔名 .json
  • 可以用 Chome about:tracing 打開或是其他 IDEs (ex. Qt Creator)
• --profiling-format=fmt
  • fmt 目前只支援 google-trace

一樣看個例子
CMakeLists.txt

cmake_minimum_required(VERSION 3.27)
project(ItHome2023)

message(STATUS "Hello World!")

cmake --profiling-output=prof-test.json \
      --profiling-format=google-trace \
      -S ../src \
      -B .

然後我們把統計結果 prof-test.json 下載下來
打開瀏覽器, 在網址輸入 chrome://tracing
把剛剛下載的統計結果拖拉或是上傳
就能得到結果啦!

可以看到 try_compile() 和 execute_process() 占最大宗, 但由於這兩者是 CMake 內部的指令, 所以請忽略他們, 向上找 call stack 看是哪些指令造成頻繁執行這兩個指令的

由於這個範例只有呼叫 message(), 花的時間太少, 從圖上找根本是大海撈針...
所以, 我們直接搜尋 message 後, 找到呼叫的時間在 443.46ms 處, 將圖片放大後就可以找到他了

Day 24 會介紹如何加速!

預告

下一篇, 終於要來介紹 CMake3.0 時代的概念 Target 和 Target-Centered Model 了, 等到了解 CMake 中 target 的概念後, 就可以開始寫我們的第一個 CMake 專案啦!