まずログ種別の定義をrte_log_register()の関数で設定します。今回は初期化処理に"app_main"、パケット処理に"app_fwd"というログ種別を使います。rte_log_register()でログ種別を設定すると返り値でログ種別のIDが払い出されるので、このIDをログ機能の各種APIで利用していくことになります。今回紹介するログ出力のマクロRTE_LOG()では、ログ種別のIDを"RTE_LOGTYPE_"というプレフィックスでのマクロ名称で使用することが条件になりますので、その条件に従った命名で定義を行います。プレフィックス以外の命名規則は特にありませんが、分かりやすいように"app_main"で設定したログ種別のIDは"RTE_LOGTYPE_APP_MAIN"と命名すると良いかと思います。

なおログ種別の命名にこだわりが無ければ、DPDKでデフォルトで用意されているRTE_LOGTYPE_USER1～RTE_LOGTYPE_USER8というログ種別のIDが用意されているので、こちらを使っても構いません。その場合はrte_log_register()の処理や特殊なプレフィックスを使ったマクロ定義が不要です。

#define RTE_LOGTYPE_APP_MAIN rte_log_register("app_main")
#define RTE_LOGTYPE_APP_FWD rte_log_register("app_forward")

次にログレベルを設定します。ログ出力処理には必ずログレベルを指定しますが、実際に出力するかどうかはシステムのログ出力の優先度と比較し、その優先度より高ければログ出力するようになります。例えばログ出力処理でログレベルを「INFO」と設定した場合、システムのログ出力の優先度が「INFO」よりも高いレベルで設定されていた場合はログが出力されません。DPDKで指定可能なログレベルを以下に示します。

DPDKのログレベル一覧（プライオリティが高い順に列挙）

ログ出力の優先度は全体に1つ設定すれば良いですが、必要に応じて「ログ種別」毎に設定することもできます。DPDKでは全体に設定するログ出力の優先度を「グローバル」の「ログレベル」と表現しています。「グローバル」の設定と「ログ種別」毎の優先度の判定は以下のイメージとなります。「ログ種別」毎の設定が特にない場合は判定自体スキップされます。


グローバルのログレベルの設定にはrte_log_set_global_level()、ログ種別ごとのログレベル設定にはrte_log_set_level()を使います。今回は、グローバルのログレベルを「RTE_LOG_INFO」に、ログ種別(app_main)のログレベルを「RTE_LOG_ERROR」に設定しました。こうすることで、app_mainのログはERRORレベル未満のものは出力を抑止できるとともに、他のログ種別はINFOレベルで出力することができます。

/* グローバルのログレベル */
rte_log_set_global_level(RTE_LOG_INFO);
/* ログ種別ごとのログレベル */
rte_log_set_level(RTE_LOGTYPE_APP_MAIN, RTE_LOG_ERROR);

【APIリファレンス】
rte_log_register

rte_log_set_global_level

rte_log_set_level

それでは、サンプルプログラムの初期化処理にRTE_LOG()を埋め込みます。ここでは初期化完了を示すメッセージをログレベルを「INFO」で出力するようにします。また、利用可能なポート数を取得してログレベルを「DEBUG」で出力します。なお、rte_eth_dev_count_avail()は、DPDKアプリケーションの作成 初期化処理編 ～DPDK入門 第7回～ の「EALの初期化」で説明しています。

・・・
RTE_LOG(INFO, APP_MAIN, "Initialize DPDK done.\n");
RTE_LOG(DEBUG, APP_MAIN, "Avail device num = %u\n", rte_eth_dev_count_avail());
・・・

RTE_LOG()のパラメータに関して解説します。なお、RTE_LOG_DP()のパラメータについても同様となります。
- 第1パラメータは、ログレベルを指定します。この時プレフィックス(RTE_LOG_)は付けないようにしてください。
- 第2パラメータは、ログ種別を指定します。この時プレフィックス(RTE_LOGTYPE_)は付けないようにしてください。
- 第3パラメータは、出力するメッセージをprintf()の書式で指定します。

【APIリファレンス】
RTE_LOG

次にパケット処理にRTE_LOG_DP()を埋め込みます。RTE_LOG_DP()を利用したログは、DPDKのconfigファイル(※1)の「CONFIG_RTE_LOG_DP_LEVEL」に指定したログレベル未満のプライオリティはコンパイル対象外にすることができ、性能を損なわないような考慮が簡単に実現できます。「CONFIG_RTE_LOG_DP_LEVEL」のデフォルト値は"RTE_LOG_INFO"のログレベルなっているので、RTE_LOG_DP()でDEBUGログを出力したい場合は、CONFIG_RTE_LOG_DP_LEVELを"RTE_LOG_DEBUG"を設定してコンパイルして下さい。

▼dpdk-＜version＞/＜target＞/.config

・・・
CONFIG_RTE_LOG_DP_LEVEL=RTE_LOG_INFO
・・・

今回はログの出力内容の例として、パケットの内容を表示したいケースが考えられます。ここでは受信したパケットの先頭6byteを出力する例を紹介します。パケットの内容を出力するため、パケットバッファの内容を参照する必要があります。rte_pktmbuf_mtod()でパケットバッファのアドレスを取得し、16進でログに出力します。

// 6byteの情報を16進数のchar型で確保する配列を用意。
// 1byteの情報は16進数では2文字で表現できるため、6*2+1(終端文字)byteの領域を確保する。
char str[(6 * 2) + 1] = {0};

// パケットバッファのアドレスを16進文字に変換して領域に書き込みログに出力する
uint8_t *dat = rte_pktmbuf_mtod(pkt, uint8_t *);  // pktはパケットバッファのポインタ
for (int i = 0; i < 6; i++) sprintf(&str[i * 2], "%02x", *(dat + i));
RTE_LOG_DP(DEBUG, APP_FWD, "[Dump 6byte] %s\n", str);

それでは実際にログを出力します。動作確認の環境はDPDKのパケット処理 ～DPDK入門 第2回～と同様です。また、パケット処理のログを確認するために、以前紹介したncコマンドを、tailコマンドを使って説明します。

まず、今回のソースコード一式(ソースコードとMakefile)を格納したディレクトリ"src"を、ホストBのホームディレクトリ配下に配置します。

「log.c」をコンパイル対象に含めるため、Makefileの変数："SRCS-y"に追加します。

▼ ~/src/Makefile

#SRCS-y := fwd.c main.c
SRCS-y := log.c fwd.c main.c

これまでと同様に、ソースコードをコンパイルします。

ログはコンソール上の標準出力と、"/var/log/syslog"に出力されます。ホストBで別のコンソールを立ち上げ、-fオプションを付けたtailコマンドを実行すると、syslogファイルに出力される状況がリアルタイムに確認できます。

続いてDPDKアプリケーションを起動します、起動方法はこれまでと変わりありません。

今回追加したログを確認下さい。ソースコードに仕込んだログが出力されています。今回は「グローバルのログレベル」をINFOに設定したので、DEBUGログは出力されていないことが分かります。

今度はDEBUGログを出力するように変更してみます。一旦「ctrl+c」でDPDKアプリケーションを停止してからソースコードを編集します。DEBUGログを出力するため、rte_log_set_global_level()で設定するログレベルを「RTE_LOG_DEBUG」変更します。また、srcコード上も好きなメッセージをDEBUGレベルで追記してみてください。

▼ ログレベル設定定義を変更(src/log.c)

/* グローバルのログレベル */
//rte_log_set_global_level(RTE_LOG_INFO);
rte_log_set_global_level(RTE_LOG_DEBUG);

再度DPDKアプリケーションをコンパイルして起動します。

DPDKアプリケーション起動後、syslogの内容を確認すると、DEBUGログが出力されました。

次に、パケット処理時のDEBUGログの動作を確認します。まず、ホストAのeth0からパケットを送信します。方法はDPDKのパケット処理 ～DPDK入門 第2回～と同じなので、細かい説明は割愛します。

この箇所はDEBUGレベルでRTE_LOG_DP()を利用しました。そのため、普通にコンパイルした場合は、DEBUGログは出力されません。出力するためには、DPDKのconfigファイルの"CONFIG_RTE_LOG_DP_LEVEL"を"RTE_LOG_DEBUG"に書き換えます。

▼dpdk-＜version＞/＜target＞/.config

・・・
#CONFIG_RTE_LOG_DP_LEVEL=RTE_LOG_INFO
CONFIG_RTE_LOG_DP_LEVEL=RTE_LOG_DEBUG
・・・

CONFIG_RTE_LOG_DP_LEVELの設定反映のため、一旦「ctrl+c」でDPDKアプリケーションを停止してから、DPDKライブラリとDPDKアプリケーションを再コンパイルします。

DPDKアプリケーションを起動します。RTE_LOG_DP()のDEBUGログが有効になっていると、起動時にDPDKが「データパスのDEBUGログが有効になっているため性能が低下します」という警告が表示されます。

再度ホストAからUDPパケットを送信します。

DEBUGログでパケットの先頭6byteの情報が出力されていることが分かります。尚、先頭6byteは宛先macアドレスになりますので、環境に応じた出力の値になっていることを確認してみてください。