天天看點
傳回

嵌入式基礎--日志子產品簡陋的設計使用printf添加更多的資訊

大家晚上好。今天來講講調試程式的重要方法：列印日志。無論開發何種程式，單片機，手機APP，電腦用戶端，還是伺服器，日志都是最基礎也是最重要的調試手段。

手機APP，電腦用戶端和伺服器的開發環境往往提供了功能豐富的日志接口。比如linux的syslog子產品提供如下日志函數：

void openlog(const char *ident, int logopt, int facility);
void closelog(void);
void syslog(int priority, const char *message, arguments...);

其記錄的每條日志包含時間，級别，來源和内容，可根據配置過濾低級别的日志。下圖中的日志，紅框是時間，黃框是來源，綠框是内容。

嵌入式基礎--日志子產品簡陋的設計使用printf添加更多的資訊

單片機的開發則大不相同，其開發環境中往往不會提供日志接口。單片機的驅動庫往往隻提供基礎的操作外設的接口，如uart，i2c，spi，而不提供高層次的SDK。這就需要我們自己來設計。

單片機日志接口比較簡單的實作，是将日志從序列槽輸出，在電腦上可通過諸多序列槽軟體來檢視。向序列槽輸出字元嘛，看着簡單，其實大有文章。簡陋的設計與精心周全的設計将使日後的代碼開發和調試産生巨大差異。

簡陋的設計

先看一個簡陋至極的接口：

void drv_uart_send(uart_t *uart, void *buf, int len);

void log_print(char *buf , unsigned int len)
{
    drv_uart_send(&uart1, buf, len);
}

log_print将buf的前len位元組的内容輸出到調試序列槽(uart1)，其實就是對序列槽輸出函數進行簡單的封裝，使使用者在輸出日志時不需要傳入序列槽執行個體。

大家覺得這個日志接口有沒有問題，好不好用呢？

該接口很簡陋，這是毫無疑問的。不僅如此，它存在一個非常不合理的設計：既然是列印字元串，那就不需要len參數。因為字元串以’\0’結尾，log_print内部完全可以判斷字元串的長度。如果要傳字元串長度的話，在調用時會非常尴尬。比如，在網絡初始化成功後，想列印"network initialize succeed"，該怎麼調用呢？

下面這種調用顯然有問題，引入了重複代碼。當需要修改日志内容時，需要修改兩處，容易遺漏。

要不這樣？這簡直就是掩耳盜鈴。看似沒有重複代碼，實則并沒有解決重複代碼引發的問題。當内容長度變化時，還是得更新長度參數。

各位不要笑，上面這種調用方法絕非筆者杜撰出來，而是在筆者近期接手的一個項目中大量出現的。

那這樣呗？這是沒啥問題了，不過在列印日志前，還得定義一個變量，是不是相當麻煩？

const char *str = "network initialize succeed\n";
log_print(str, strlen(str));

上述三種調用方法，前兩者均存在問題，第三種也很尴尬。問題的根源出在log_print接口的設計上，想要避免尴尬，還得從源頭解決。其實很簡單：

void drv_uart_send_str(uart_t *uart, const char *str)
{
    drv_uart_send(uart, str, strlen(str));
}

void log_print(char *buf)
{
    drv_uart_send_str(&uart1, buf);
    drv_uart_send_str("\n");
}

做了兩項修改：

  1. 在序列槽層面添加列印字元串的函數，進而使log_print不需要長度參數。
  2. log_print在輸出日志内容之後自動換行，進而避免每條日志中都要加’\n’。

現在列印日志就舒服多了：

非常簡單的修改，就可極大改善調用體驗。人生而懶惰，懶惰不一定有大問題，問題在于，要懶惰得恰到好處。如果在設計底層接口時偷懶，則日後寫應用層代碼時将堕入萬劫不複之深淵。如果想在調用時舒服些，那就需要在設計底層時多花些心思。

使用printf

修改過後的log_print不再醜陋，但依然很簡陋。如果想列印動态的内容，如數字時，還是比較麻煩。比如列印網絡信号品質(rssi為int型變量，值為信号品質)：

char buffer[64];
snprintf(buffer, sizeof(buffer), "rssi:%d", rssi);
log_print(buffer);

簡單列印一個數字卻需要三行代碼，非常不便。這時我們可以呼叫printf函數：

相信大家肯定對printf并不陌生，這可是學習C語言時經常用到的函數，其将内容列印到标準輸出。單片機SDK并沒有指定标準輸出，若想将printf的内容輸出到指定序列槽，則需要實作printf所依賴的底層函數。在gcc編譯環境中（stm32cube，TRUEStudio，Code Compose Studio等均使用gcc編譯器），需要實作_write函數：

int _write(int fd, char *str, int len)
{
    drv_uart_send(&dbg_uart, str, len);
    return len;
}

drv_uart_send為筆者封裝的序列槽發送函數，dbg_uart指向調試序列槽。

_write為C庫中定義的系統函數之一。_write實作的其實是将資料寫入檔案，fd為檔案号。由printf調用_wirte時，傳入的fd為1，即标準輸出stdout。其他函數，如fprintf，fwrite也會調用_write，它們傳入的fd指向相關檔案。是以上述_write函數的實作并不嚴謹，它忽略了fd參數，不管是什麼檔案的寫操作，均輸出到排程序列槽。

嚴謹的設計應該這樣：

int _write(int fd, char *str, int len)
{
    if (fd == stdout->_file)
    {
        drv_uart_send(&dbg_uart, str, len);
    }

    return len;
}

不過在不使用檔案系統的情況下，也不會操作其他檔案，這個懶也可以偷。

添加更多的資訊

使用printf已經比之前的log_print友善許多，不過仍然有改進的空間。

快速打開或關閉日志

在調試階段，可能需要列印較多的日志來觀察效果和跟蹤問題。由于過多的日志可能降低程式的實時性，也暴露了實作的細節，是以在正式運作時（比如商用傳遞或者比賽驗收）需要關閉全部或者大部分日志。如果寫了大量的printf語句的話，一個個注釋掉顯然是件麻煩的事情。我們需要有一個能夠快速打開或關閉日志的功能。

時間資訊

有時我們不僅想要知道程式運作的結果，還想觀察關鍵步驟執行的時間。比如某步執行了多長時間，某個定時任務執行的周期是否正确。如果日志中包含時間資訊（比如從啟動到現在所經過的毫秒）就會很友善觀察。

[10.011] schedule task1
[12.011] schedule task1
[12.015] schedule task2
[14.011] schedule task1
[16.011] schedule task1
[16.015] schedule task2

來源和級别

當日志較多時，如果能列印日志的來源（檔案名或子產品名，函數名，代碼行數），則更友善檢視和定位問題。在多人合作開發時，這點尤為重要。

如果根據日志内容的重要性對日志分級，以不同的顔色來顯示不同級别的内容，則更容易觀察。

下圖中：

  • 白色為verbose級别，一般用于列印碼流。
  • 藍色為debug級别，包含了大量的調試資訊。
  • 綠色為info級别，通常列印關鍵步驟的結果。
  • 紅色為error級别，列印錯誤資訊。

下圖紅框中為日志來源，由子產品名和代碼行數組成。

嵌入式基礎--日志子產品簡陋的設計使用printf添加更多的資訊

正式運作時，往往不需要verbose和debug日志，保留info和error日志。

實作

實作上述功能會稍微複雜些，下面做一些簡單的介紹。

定義日志級别：

/* Debug level */
#define LOG_LEVEL_FATAL         0
#define LOG_LEVEL_ERROR         1
#define LOG_LEVEL_WARN          2
#define LOG_LEVEL_INFO          3
#define LOG_LEVEL_DEBUG         4
#define LOG_LEVEL_VERBOSE       5

定義宏LOG_D以列印調試級别的日志：

#if LOG_LEVEL >= LOG_LEVEL_DEBUG
#define LOG_D(fmt, ...) logger_output(LOG_LEVEL_DEBUG, LOG_TAG, __LINE__, fmt, ##__VA_ARGS__)
#else
#define LOG_D(fmt, ...)
#endif

解釋幾點内容：

  • LOG_LEVEL為目前日志級别，其可以控制是否列印調試級别的日志。此宏在使用者代碼中定義，而不是頭檔案這中。這樣一來，不同的代碼檔案可以單獨控制自己日志的級别。有些開發完畢的檔案可調高日志級别（數值越小，級别越高）以精簡日志，而開發中的檔案可調低日志級别。
  • …用于接收變長參數，編譯器做宏替換時，會将…接收的參數集替換到__VA_ARGS__所在位置。
  • ##為辨別連接配接符，這裡是用于處理變長參數集為空的場景。此時，##會吞噬前面的逗号。
  • LOG_D在進行宏替換時，會加上日志級别（調試級别），标簽名（LOG_TAG，同樣在使用者代碼中定義），代碼行數資訊。

每一個使用者代碼在導入日志子產品頭檔案時，需要指定标簽名稱和日志級别：

#define LOG_TAG 	"app"
#define LOG_LEVEL	LOG_LEVEL_DEBUG
#include "logger.h"

使用起來很簡單，當printf使用即可，比如：

LOG_D("this is a debug log");
LOG_D("rssi:%d", 30);

如果剛才沒有了解…和##的話，這裡結合示例再說明下。

上述示例中，

LOG_D("rssi:%d", 30)

中的

"rssi:%d"

是格式化字元串，對應于

LOG_D(fmt, ...)

中的fmt參數，30則屬于變長參數。為了便于了解，筆者給出中間替換結果，即LOG_LEVEL_DEBUG之類的不替換：

至于

LOG_D("this is a debug log")

,如果沒有##的話，将被替換為：

有沒有注意最右邊有一個單獨的逗号？##的作用就是在這種情況下把逗号給吃掉。

logger_output的實作如下，先列印時間和來源，之後調用了va_list版本的snprintf，即vsnprintf，以列印使用者傳遞的格式化字元串和變長參數。關于va_list，改天單獨出篇文章講解。

void logger_output(int level, const char *tag, int line_num, const char *fmt, ...)
{
    static char buf[LOG_BUF_SIZE];

    va_list args;
    int idx = 0;
    uint32_t tick = sys_get_time();

    level = MATH_MAX(0, level);
    level = MATH_MIN(level, ARRAY_SIZE(LEVEL_PREFIX) - 1);
    idx += snprintf(buf + idx, sizeof(buf) - idx, "[%lu.%03lu] [%s:%d] %s",
            tick / 1000, tick % 1000, tag, line_num, LEVEL_PREFIX[level]);

    va_start(args, fmt);
    idx += vsnprintf(buf + idx, sizeof(buf) - idx, fmt, args);
    va_end(args);

    idx += snprintf(buf + idx, sizeof(buf) - idx, "\r\n" NOR);

    drv_uart_send(&dbg_uart, buf, idx);
}

其他級别的日志接口，如LOG_I，LOG_W等，日志接口的詳細實作與使用示例，參見筆者基于stm32f407建立的demo工程：

位址：https://gitee.com/njupt_elec/demo

代碼：utils/logger.h, utils/logger.c

調用示例：examples/01_log/example.c，使用時需要打開examples/examples.h中的EXAMPLE_SHOW_LOG。

下圖為examples/01_log/example.c的效果，想要看到彩色的日志的話，可使用Tera Term或SecureCRT這兩款序列槽軟體。

嵌入式基礎--日志子產品簡陋的設計使用printf添加更多的資訊
嵌入式基礎 單片機 嵌入式
上一篇: 【轉】C語言的5種存儲類以及關鍵字volatile、restrict
下一篇: 機械轉嵌入式還是it？學嵌入式好還是java好？

繼續閱讀