Thursday, December 29, 2016

GStreamer でプログラミング 8 (Log)

1 はじめに

デバッグは、プログラムを書く上で避けては通れない作業の1つです。今回は、デバッグ時に役に立つ logger についてです。

2 すべてのログは gst_debug_log() に通ず

GStreamer のログは、どのマクロを使っても最終的には gst_debug_log() に展開されます。なので、この関数が使えるようになればどのマクロでも使いこなせます。 

void
gst_debug_log (GstDebugCategory *category,
               GstDebugLevel level,
               const gchar *file,
               const gchar *function,
               gint line,
               GObject *object,
               const gchar *format,
               ...);
category

カテゴリーと呼ばれる、ログの種別を指定します。エレメントや、エレメントで使われるライブラリーなどは、小文字を使ったカテゴリー名を使います。例えば pipeline 、 bus 、 bin 、 basesink 、 basesrc 、 videotestsrc など、エレメントの名前がそのまま使われている事が多いです。

逆に GStreamer のコアは、 GST_ で始まるカテゴリー名を使っています。 GST_STATES 、 GST_CLOCK 、 GST_PADS 、 GST_BUS など抽象的な概念、 GST_INIT や GST_MEMORY 、GST_PLUGIN_LOADING 、 GST_REGISTRY などコア機能部分などです。

自分でアプリを作成する場合には、自分のアプリのカテゴリーを作るとログを分別するのに便利です。これについては後ほど

特に指定がなければ GST_CAT_DEFAULT を使います。こちらも後ほど詳しく説明します

level

severity と呼ばれる「ヤバイ度」を表すレベルを指定します。重度の方から

  • GST_LEVEL_ERROR
  • GST_LEVEL_WARNING
  • GST_LEVEL_FIXME
  • GST_LEVEL_INFO
  • GST_LEVEL_DEBUG
  • GST_LEVEL_LOG
  • GST_LEVEL_TRACE
  • GST_LEVEL_MEMDUMP

となっています。 ERROR から順に 1, 2, 3… と番号でも表わすことができます。 TRACE が 7 で、8 が バージョン 1.10.0 現在では定義されておらず、 MEMDUMP は 9 です

file / function / line
ファイル名、関数名、行番号を指定します。 gst_debug_log() を直接呼び出すことは、実際のコードではあまりなく、それぞれ __FILE__ __fun__ __LINE__ がマクロで指定されます。 gst_debug_log() を直接呼ぶなら嘘を書くこともできます
object
GObject から派生したオジェクトを渡すことができます。 gst_debug_print_object() を使ってオジェクトを綺麗に print してくれます
format / …
printf() と同じく format に続いて引数を列べます
#include <gst/gst.h>

int main(int argc, char *argv[])
{
        gst_init(&argc, &argv);

        gst_debug_log(GST_CAT_DEFAULT,
                      GST_LEVEL_ERROR,
                      "debuglog.c",
                      "main",
                      10,
                      NULL,
                      "hello from gst_debug_log!");

        GST_CAT_LEVEL_LOG(GST_CAT_DEFAULT,
                          GST_LEVEL_ERROR,
                          NULL,
                          "this should be similer to the line above");

        return 0;
}

$ gcc -Wall -Wextra -g $(pkg-config --cflags --libs gstreamer-1.0) debuglog.c
$ ./a.out
$ ./a.out --gst-debug 1
0:00:00.012686366 29952 0x56142d48fe90 ERROR                default debuglog.c:10:main: hello from gst_debug_log!
0:00:00.012716649 29952 0x56142d48fe90 ERROR                default debuglog.c:18:main: this should be similer to the line above
$ ./a.out --gst-debug ERROR
0:00:00.016021714 29979 0x55f65aae9e90 ERROR                default debuglog.c:10:main: hello from gst_debug_log!
0:00:00.016052525 29979 0x55f65aae9e90 ERROR                default debuglog.c:18:main: this should be similer to the line above
$ ./a.out --gst-debug default:6
0:00:00.000672566 30012 0x560b988048f0 DEBUG                default gstelement.c:194:gst_element_setup_thread_pool: creating element thread pool
0:00:00.022098288 30012 0x560b988048f0 DEBUG                default gsttracerutils.c:78:_priv_gst_tracing_init: Initializing GstTracer
0:00:00.022144095 30012 0x560b988048f0 ERROR                default debuglog.c:10:main: hello from gst_debug_log!
0:00:00.022150816 30012 0x560b988048f0 ERROR                default debuglog.c:18:main: this should be similer to the line above

gst-launch-1.0 ではなく、自作のアプリでも gst_init() をしていると、上記のように --gst-debug が使えます。説明のために GST_LEVEL_ERROR を使っています。 GST_LEVEL_ERROR は 1 と等価なので --gst-debug 1 と指定しても --gst-debug ERROR と指定しても同じ結果になります。

--gst-debug の代りに、環境変数 GST_DEBUG でも同じように指定できます。

--gst-debug のフォーマットは、 「カテゴリー : レベル」と指定します。サンプルコードで、カテゴリーが "default" の ERROR だけを表示したい場合は default:1 、または default:ERROR と指定します。 LOG (6) や DEBUG (5) まで表示したい場合は default:6 と指定します。 gstelement.c や gsttracerutils.c にも default カテゴリーを使っているものがあるのが分ります。

3 便利なマクロ達

実際にコードを書いている時には gst_debug_log() は面倒なので使いません。もっと簡単に使える以下のマクロを使います。

  • GST_ERROR()
  • GST_WARNING()
  • GST_INFO()
  • GST_DEBUG()
  • GST_LOG()
  • GST_FIXME()
  • GST_TRACE()

それぞれ、suffix になっているレベルでログを表示してくれます。カテゴリーは GST_CAT_DEFAULT です。 

#include <gst/gst.h>

int main(int argc, char *argv[])
{
        gst_init(&argc, &argv);

        GST_ERROR("foo");   // 1
        GST_WARNING("foo"); // 2
        GST_INFO("foo");    // 3
        GST_DEBUG("foo");   // 4
        GST_LOG("foo");     // 5
        GST_FIXME("foo");   // 6
        GST_TRACE("foo");   // 7

        GST_CAT_ERROR(GST_CAT_DEFAULT, "foo");   // 1
        GST_CAT_WARNING(GST_CAT_DEFAULT, "foo"); // 2
        GST_CAT_INFO(GST_CAT_DEFAULT, "foo");    // 3
        GST_CAT_DEBUG(GST_CAT_DEFAULT, "foo");   // 4
        GST_CAT_LOG(GST_CAT_DEFAULT, "foo");     // 5
        GST_CAT_FIXME(GST_CAT_DEFAULT, "foo");   // 6
        GST_CAT_TRACE(GST_CAT_DEFAULT, "foo");   // 7

        return 0;
}

つまり、上と下のマクロは同じ意味になります。上の方がカテゴリーを省略して書けるので便利ですね。GStreamer の本体でも良く使われているマクロの1つです。 

$ ./a.out --gst-debug default:6
0:00:00.000326411 31064 0x55e3cd8a38f0 DEBUG                default gstelement.c:194:gst_element_setup_thread_pool: creating element thread pool
0:00:00.012841797 31064 0x55e3cd8a38f0 DEBUG                default gsttracerutils.c:78:_priv_gst_tracing_init: Initializing GstTracer
0:00:00.012881297 31064 0x55e3cd8a38f0 ERROR                default log.c:12:main: foo
0:00:00.012886168 31064 0x55e3cd8a38f0 WARN                 default log.c:13:main: foo
0:00:00.012890248 31064 0x55e3cd8a38f0 INFO                 default log.c:14:main: foo
0:00:00.012893221 31064 0x55e3cd8a38f0 DEBUG                default log.c:15:main: foo
0:00:00.012898387 31064 0x55e3cd8a38f0 LOG                  default log.c:16:main: foo
0:00:00.012901336 31064 0x55e3cd8a38f0 FIXME                default log.c:17:main: foo
0:00:00.012904926 31064 0x55e3cd8a38f0 ERROR                default log.c:20:main: foo
0:00:00.012909571 31064 0x55e3cd8a38f0 WARN                 default log.c:21:main: foo
0:00:00.012913609 31064 0x55e3cd8a38f0 INFO                 default log.c:22:main: foo
0:00:00.012917039 31064 0x55e3cd8a38f0 DEBUG                default log.c:23:main: foo
0:00:00.012919887 31064 0x55e3cd8a38f0 LOG                  default log.c:24:main: foo
0:00:00.012923130 31064 0x55e3cd8a38f0 FIXME                default log.c:25:main: foo

:6 を :5 や :3 に変更すると表示されるものが変るので、試してみてください。

4 カテゴリーの作り方

さて、今回の本題である「自分用のカテゴリーの作り方」に入ります。

作り方は簡単で、 GstDebugCategory を1つ作るだけです。 

#include <gst/gst.h>

int main(int argc, char *argv[])
{
        GstDebugCategory *cat;

        gst_init(&argc, &argv);

        cat = _gst_debug_category_new("my category", 0, "This is my category");

        GST_CAT_ERROR(cat, "foo");
        GST_CAT_WARNING(cat, "foo");
        GST_CAT_INFO(cat, "foo");
        GST_CAT_DEBUG(cat, "foo");
        GST_CAT_LOG(cat, "foo");
        GST_CAT_FIXME(cat, "foo");
        GST_CAT_TRACE(cat, "foo");

        return 0;
}

ただ、これだと main() の中でしか使えないので、大体はファイルグローバルの変数として宣言してしまいます。 

#include <gst/gst.h>

static GstDebugCategory *cat;

int main(int argc, char *argv[])
{
        gst_init(&argc, &argv);

        cat = _gst_debug_category_new("my category", 0, "This is my category");

        GST_CAT_ERROR(cat, "foo");
        GST_CAT_WARNING(cat, "foo");
        GST_CAT_INFO(cat, "foo");
        GST_CAT_DEBUG(cat, "foo");
        GST_CAT_LOG(cat, "foo");
        GST_CAT_FIXME(cat, "foo");
        GST_CAT_TRACE(cat, "foo");

        return 0;
}

これを GST_DEBUG_CATEGORY_STATIC と GST_DEBUG_CATEGORY_INIT というマクロで書くと 

#include <gst/gst.h>

GST_DEBUG_CATEGORY_STATIC(cat);

int main(int argc, char *argv[])
{
        gst_init(&argc, &argv);

        GST_DEBUG_CATEGORY_INIT (cat, "my category", 0, "This is my category");

        GST_CAT_ERROR(cat, "foo");
        GST_CAT_WARNING(cat, "foo");
        GST_CAT_INFO(cat, "foo");
        GST_CAT_DEBUG(cat, "foo");
        GST_CAT_LOG(cat, "foo");
        GST_CAT_FIXME(cat, "foo");
        GST_CAT_TRACE(cat, "foo");

        return 0;
}

となります。 _gst_debug_category_new() がアンダーバー _ で始まっていることからも、これはマクロから使われる為だけで公開関数ではないことが分ります。

さらにカテゴリーをわざわざ指定するの面倒なので、 自分のカテゴリーを GST_CAT_DEFAULT に define してしまいます。これで、やっと GstInfo の説明に書いてあるコード と同じになりました。 

#include <gst/gst.h>

GST_DEBUG_CATEGORY_STATIC(cat);
#define GST_CAT_DEFAULT cat

int main(int argc, char *argv[])
{
        gst_init(&argc, &argv);

        GST_DEBUG_CATEGORY_INIT (cat, "my category", 0, "This is my category");

        GST_ERROR("foo");
        GST_WARNING("foo");
        GST_INFO("foo");
        GST_DEBUG("foo");
        GST_LOG("foo");
        GST_FIXME("foo");
        GST_TRACE("foo");

        return 0;
}

すると、こんな風に使えるようになります。 

$ ./a.out --gst-debug "my category":6
0:00:00.012787531 30961 0x557846935e90 ERROR            my category mycat.c:12:main: foo
0:00:00.012817629 30961 0x557846935e90 WARN             my category mycat.c:13:main: foo
0:00:00.012826697 30961 0x557846935e90 INFO             my category mycat.c:14:main: foo
0:00:00.012833958 30961 0x557846935e90 DEBUG            my category mycat.c:15:main: foo
0:00:00.012839721 30961 0x557846935e90 LOG              my category mycat.c:16:main: foo
0:00:00.012846188 30961 0x557846935e90 FIXME            my category mycat.c:17:main: foo

"my category" にはスペースが入っているので、「"」で括るのを忘れずに。

5 おわりに

アプリを書く時も、エレメントを作成する時も、とりあえずボイラープレートとして自分のカテゴリーを登録してしまうと、後からのデバッグが楽になります。 --gst-debug には複数のカテゴリーを列べることもできますし、ワイルドカード「*」での指定も可能です。自分のプログラム内で、複数のカテゴリーを登録する時に決まった形の prefix を使えば 

--gst-debug "myapp_*:6"

という感じでカテゴリーを選択できるので便利です。

ところで、 GST_CAT_DEFAULT の妙に気付いた人はいたでしょうか? 元々あった default のカテゴリーも GST_CAT_DEFAULT ですし、自分で define したのも GST_CAT_DEFAULT です。これ、考えてみると二重定義にならないのって変じゃないです?

答は、もちろんソースにあります。 gstinfo.h の 550行目あたりに 

GST_EXPORT GstDebugCategory *   GST_CAT_DEFAULT;

って書いてあるはずです。そうです、自分で define していない GST_CAT_DEFAULT は、実は大文字の変数名なんですね。

C では、すでに宣言されている変数名と同じ名前で define することは許されています。 define すると、そちらの方がプリプロセッサーで先に処理されて 自分で作成した GstDebugCategory の変数に置き換わります。

define していない場合は、GStreamer が用意している変数がそのまま使われるという仕組みです。良く考えられてますねー。

分りました? もし分からなかっったらもう一度、 gstinfo.h と上のサンプルコードをじーっと眺めてみてください。

Posted by at
Labels:

No comments:

Post a Comment

Subscribe to: Post Comments (Atom)