printfログをデバッグレベルによって切り替える方法(C言語)

gdbデバッガーを動かしながらデバッグするのが基本ですが、検証メンバーやお客様のところでしか問題が起きない場合にはログを解析することになります。

また、開発中はログ出力したいが、納品後はセキュリティ都合でログは全く出したくない場合もあります。

そういうときにログの加減を変えたいときに簡単に切り替えられるように仕組みを作り込んでから開発を行います。

その一例を教えます。

実際に使っているイメージ
デバッグのためプログラムをログ全開にしたら
仕組みを先に構築しておくとログを埋め込むのが楽！
拡張/改善ポイント

実際に使っているイメージ

int _func(const char *filename, unsigned int line, const char *funcname, int input);
#define FUNC(a) _func(__FILE__,__LINE__,__FUNCTION__,a)


int _func(const char *filename, unsigned int line, const char *funcname, int input)
{
    PRINT(DBG_APIS,"<- form %s:%d %s()",filename,line,funcname);
    PRINT(DBG_APIINF,"input = %d",input);

    if(input > 10){ //parameter check
        PRINT(DBG_ERROR|DBG_APIE,"");
        return -1;
    }
    input++;

    PRINT(DBG_APIE,"");
    return input;
}

void main(void)
{
    int ret = 0;
    dgb_set_flag(DEBUG_LEVEL_NORMAL); //デバッグレベルの設定

    ret = FUNC(100);

    PRINT(DBG_INFO,"ret = %d",ret); //通常ログ出力
    PRINT(DBG_DEBUG,"main end");   //表示されない
    return;
}

ログだらけのコードですが、「dgb_set_flag()」という関数でデバッグレベルの設定をしています。

後で全体を見せますが、引数のDEBUG_LEVEL_NORMALはbit定義のフラグの集まりです。

これを出力すると

$main
<<ERROR>>main.c(),Line80 :_func 
[INFO]ret = -1

このようなログが出るようになります。エラーログは出ていますが、なぜエラーになったのかはわからない状態です。
ここから不具合の解析をするために、

デバッグのためプログラムをログ全開にしたら

void main(void)
{
    int ret = 0;
    dgb_set_flag(DEBUG_LEVEL_ALL);　//ここを変更

    ret = FUNC(100);

    PRINT(DBG_INFO,"ret = %d",ret);
    PRINT(DBG_DEBUG,"main end");
    return;
}

というようにデバッグレベルを全部ありにしてみました。
その結果はこちら、

$main
[APIS]_func() <- form main.c:95 main()
[_func()]input = 100
<<ERROR>>main.c(),Line80 :_func 
[APIE]_func() 
[INFO]ret = -1
[DBG]main.c(),Line99 :main main end

いろいろ出てきましたが、よく読めば、
・関数がどこから呼ばれたか
・関数の引数
・関数の終わり
・エラーの起きた理由
・処理結果
などがわかり、どこに問題があったか。すぐにわかります。

プログラムがしょぼすぎてデバッグするまでもないだろ！って怒られそうですが、説明用なのでゆるして。

仕組みを先に構築しておくとログを埋め込むのが楽！

仕組みを入れてしまえば後は書きながらテストするときに確認すべき変数や分岐などのポイントが明確になっていればデバッグレベルを正しく設定して埋め込んでおくことができます。

読解はじっくり読み込んでもらったら理解できますし、皆さんの環境に合わせて拡張や変更もできると思います。

実装しながらログを埋め込む習慣の有無で後の効率が変わってくると思います。

コードの全体は最後に！

拡張/改善ポイント

サンプルのコードはなんとなくこれくらいはみんな必要かな？というレベル分けなので実際は不足することが多いと思いますのですぐ考えられる変更ポイントを列挙します。

１.エラーのときは色を付ける
　　この記事を参考にしてください。
　　でも、赤い色をつけるとエラーでもないのに勝手にバグ登録されたりするのでご注意ください。

printfで色をつけると見やすくなる(C言語)

私は大規模な組み込みソフト開発を長年行っているのですが、開発途中で動作確認する際、もともとのログがたくさん表示され自分...

2.デバッグレベルを細分化する
　　当然ですね。環境によっては機能ごとにログを分けておきたいという場合もよくあります。その時はレベル（といってもフラグですが）を追加してしまうと便利です。

3.プロセスID/スレッドIDを表示する
　　マルチプロセスやマルチスレッドでの処理が普通ですので、同じプロセスやスレッドの複数同時に使うこともよくありますので、区別するためにプロセスIDやスレッドIDを付与することで解析がはかどったりします。そのとき、プロセス/スレッド起動時と終了時のPIDのログは必須です。

4.プロセス/スレッド名を表示する
　　スレッド名は命名しておきましょう。デバッグで大活躍します。
　　スレッド名、プロセス名をログ表示すると直感的にどこの何がログを出しているかは一目瞭然になり便利です。そもそも起動されていないことが不具合だったりしますし。