2012年2月15日水曜日

Zabbixのlog[]とlogrt[]キーの動作

Zabbixにはログ監視用のアイテムとしてlog[]とlogrt[]キーがあります。ともにテキストベースのログファイルを監視し、1行を1データとしてZabbixサーバに送付、文字列マッチを行って障害判定をすることができます。

これらのキーを使ったときに、Zabbix内部ではどのような動作をしているのかというのが見えにくいですし、ログ関係はZABBIX-JPのフォーラムでもよく質問があります。私自身、質問を受けるたびに何度もソースコードを調べている気がするので、一度まとめておこうと思います。

解説に利用しているソースコードは1.8.10です。間違っていたらコメントでご指摘いただけると助かります。

log[]キーの動き

log[]キーはZabbix 1.1から追加されれいるログ監視用のキーです。1.6まではログ監視をするにはこのキーを利用する以外の手段はありませんでした。アイテムのキーには以下のように実際に監視するファイル名をそのままオプションに設定します。

log[file_path,regexp,encoding,maxlines]

regexp以降は1.8で追加されたオプションです。単純にファイルを監視するだけであれば、以下のように設定できます。

log[/var/log/messages]

logキーの処理はソースコードのsrc/zabbix_agent/logfiles.cの598行目から始まるprocess_log()関数で定義されています。

/* handling of file shrinking */
if (0 != zbx_stat(filename, &buf))
{
    zabbix_log(LOG_LEVEL_WARNING, "cannot stat [%s]: %s", filename, zbx_strerror(errno));
    return ret;
}

ここでファイルをの状態を取得し、

if (buf.st_size < *lastlogsize)
    *lastlogsize = 0;

ここでファイルのサイズがlastlogsizeよりも小さければ、lastlogsizeを0に設定しています。

lastlogsizeというのはログファイルをどこまで読んだかを記録しておく変数で、つまり、前回読んだバイト数よりもファイルが小さくなっていれば、ファイルが新規作成もしくはローテートされたと判断して、ファイルを先頭から読みにいくようになっています。

if (-1 == (f = zbx_open(filename, O_RDONLY)))
{
    zabbix_log(LOG_LEVEL_WARNING, "cannot open [%s]: %s", filename, zbx_strerror(errno));
    return ret;
}

ファイルをREADONLYでオープンし、

if ((off_t)-1 != lseek(f, (off_t)*lastlogsize, SEEK_SET))
{
    if (-1 != (nbytes = zbx_read(f, buffer, sizeof(buffer), encoding)))
    {
        if (0 != nbytes)
        {
            *lastlogsize += nbytes;
            *value = convert_to_utf8(buffer, nbytes, encoding);
            zbx_rtrim(*value, "\r\n ");
        }
        ret = SUCCEED;
    }
    else
        zabbix_log(LOG_LEVEL_WARNING, "cannot read from [%s]: %s", filename, zbx_strerror(errno));
}
else
    zabbix_log(LOG_LEVEL_WARNING, "cannot set position to [%li] for [%s]: %s", *lastlogsize, filename, zbx_strerror(errno));

close(f);

lastlogsize以降の文字列をutf8に変換しながら読み込み、読んだバイト分lastlogsizeを増加させ、ファイルをクローズしています。このときbufferのサイズはMAX_BUFFER_LENで定義されている65536B=64KBなので、それを超えない行末までを1度に読み込んでいます。

ここでvalueに読み込まれた文字列とlastvalueの値は最終的にソースのsrc/zabbix_agent/active.cの753行目あたりからの処理

while (SUCCEED == (ret = process_log(filename, &lastlogsize, &value, encoding)))
{
    if (NULL == value) /* End of file. The file could become empty, must save `lastlogsize'. */
    {
        active_metrics[i].lastlogsize = lastlogsize;
        break;
    }

    if (SUCCEED == regexp_match_ex(regexps, regexps_num, value, pattern, ZBX_CASE_SENSITIVE))
    {
        send_err = process_value(server, port, CONFIG_HOSTNAME,
                active_metrics[i].key_orig, value, &lastlogsize,
                NULL, NULL, NULL, NULL, NULL, 1);
        s_count++;
    }
    p_count++;

    zbx_free(value);

    if (SUCCEED == send_err)
        active_metrics[i].lastlogsize = lastlogsize;
    else
    { /* buffer is full, stop processing active checks till the buffer is cleared */
        lastlogsize = active_metrics[i].lastlogsize;
        goto ret;
    }

    /* do not flood Zabbix server if file grows too fast */
    if (s_count >= (maxlines_persec * active_metrics[i].refresh))
        break;

    /* do not flood local system if file grows too fast */
    if (p_count >= (4 * maxlines_persec * active_metrics[i].refresh))
        break;
} /* while processing a log */

でvalueの値はprocess_value()関数に処理され、lastvalueの値はactive_metrics配列にセットされています。active_metrics配列にはZabbixサーバから取得したアクティブチェックのアイテム設定が入っています。これらの値は最終的にZabbixサーバに送付され処理されます。

このwhile部分は1回の監視処理で1度呼ばれ、gotoまたはbreakが呼ばれるまで繰り返しprocess_log()関数を実行して64KBづつファイルを読んでいます。

ループを抜ける条件としては、

  • ログファイルの末尾まで読む
  • Zabbixエージェントのバッファ(Zabbixサーバに送信前のデータを溜めておくもの)が一杯になる
  • s_count(Zabbixサーバに送付する行数)がmaxlinex_persec * アイテムの監視間隔(秒)に達する
  • p_count(読み込んだログの行数)が4 * maxlinex_persec * アイテムの監視間隔(秒)に達する

のいずれかです。ログの途中で終了した場合は次の監視の時に続きから読みます。

maxlines_persecはlog[]キーのmaxlinesパラメータで指定された値か、zabbix_agentd.confのMaxLinesPerSecondパラメータで指定された値を使用します。

logrt[]キーの動き

logrt[]キーはローテーションをするログファイルを監視するためのキーで、1.8から新しく追加されています。アイテムのキーには以下のように設定します。

logrt[file_format,regexp,encoding,maxlines]

log[]キーと異なるのはファイル指定部分に正規表現が利用できる点です。例えば以下のように指定します。

logrt[/var/log/messages.*]

logrt[]キーの動作としてはフォルダを探索し、マッチするファイルを抜き出し、監視すべきファイルを選定してからファイルを読みます。この処理が入るためlog[]キーよりは動作が複雑です。それ以外はlog[]キーとほぼ同じ動作をしますので、ここではファイルの選択ロジックについてのみ解説します。

ちなみに、ファイル名部分に利用できるのは正規表現です。正規表現をシェルのワイルドカードと誤解している人をよく見かけます。正規表現で*は「直前の文字の0回以上の繰り返し」なので、間違えると思いがけないファイルまで読んでしまう場合があるので注意してください。

logrtキーの処理はソースコードのsrc/zabbix_agent/logfiles.cの366行目から始まるprocess_logrt()関数で定義されています。Windowsとそれ以外で処理が分かれているので、ここではWindows部分の解説は飛ばします。

/* splitting filename */
if (SUCCEED != split_filename(filename, &directory, &format))
{
    zabbix_log(LOG_LEVEL_WARNING, "filename [%s] does not contain a valid directory and/or format", filename);
    return FAIL;
}

ここで指定されたパスをディレクトリとファイル名に分けて、

if (NULL == (dir = opendir(directory)))
{
    zabbix_log(LOG_LEVEL_WARNING, "cannot open directory [%s] for reading: %s", directory, zbx_strerror(errno));
    zbx_free(directory);
    zbx_free(format);
    return FAIL;
}

ディレクトリをオープン

while (NULL != (d_ent = readdir(dir)))
{
    logfile_candidate = zbx_dsprintf(logfile_candidate, "%s%s", directory, d_ent->d_name);

    if (-1 == zbx_stat(logfile_candidate, &file_buf) || !S_ISREG(file_buf.st_mode))
    {
        zabbix_log(LOG_LEVEL_DEBUG, "cannot process read entry [%s]", logfile_candidate);
    }
    else if (NULL != zbx_regexp_match(d_ent->d_name, format, &length))
    {
        zabbix_log(LOG_LEVEL_DEBUG, "adding the file [%s] to logfiles", logfile_candidate);
        add_logfile(&logfiles, &logfiles_alloc, &logfiles_num, d_ent->d_name, (int)file_buf.st_mtime);
    }
    else
        zabbix_log(LOG_LEVEL_DEBUG, "[%s] does not match [%s]", logfile_candidate, format);

    zbx_free(logfile_candidate);
}

ディレクトリにあるファイルから、指定された正規表現にマッチするファイルを探してlogfiles配列に追加しています。

途中にあるadd_logfile()関数でlogfiles配列への追加処理を行っているのですが、この関数内は

  • ファイルのmtime(ファイルの更新日時)が古い順
  • mtimeが同じ場合はアルファベット/数字の降順(z->a, 9->0)

に並ぶように処理されています。

/* find the oldest file that match */
for (i = 0; i < logfiles_num; i++)
{
    if (logfiles[i].mtime < *mtime)
        continue;   /* not interested in mtimes less than the given mtime */
    else
        break;  /* the first occurrence is found */
}

ここで*mtimeとなっているのは、前回ログを読み込んだ際に記憶しておいたmtimeです。つまり、logfiles配列にあるログファイルのmtimeと前回読んだファイルのmtimeを比較して、最初に見つけた「前回よりもmtimeが新しいファイル」のインデックスが変数iに入ります。logfiles配列の先頭から読んでいるので、配列の順番が重要です。

/* escaping those with the same mtime, taking the latest one (without exceptions!) */
for (j = i + 1; j < logfiles_num; j++)
{
    if (logfiles[j].mtime == logfiles[i].mtime)
        i = j;  /* moving to the newer one */
    else
        break;  /* all next mtimes are bigger */
}

ここでは先ほど見つけたmtimeが新しいログファイルを基準に、それよりもlogfiles配列の後ろにあるファイルを探索してmtimeを比較しています。mtimeが同じファイルがあれば、より配列の後ろにあるファイルが選択されます。(実際にはインデックスが変数iに入る)

/* if all mtimes are less than the given one, take the latest file from existing ones */
if (0 < logfiles_num && i == logfiles_num)
    i = logfiles_num - 1;   /* i cannot be bigger than logfiles_num */

最終的にインデックスiが配列の最後まで行ってしまった場合は、logfiles配列の一番後ろのログファイルが選択されます。

ここから実際にログファイルを読む部分です。少し長いですがそのまま貼付けます。

/* processing matched or moving to the newer one and repeating the cycle */
for ( ; i < logfiles_num; i++)
{
    logfile_candidate = zbx_dsprintf(logfile_candidate, "%s%s", directory, logfiles[i].filename);
    if (0 != zbx_stat(logfile_candidate, &file_buf))/* situation could have changed */
    {
        zabbix_log(LOG_LEVEL_WARNING, "cannot stat [%s]: %s", logfile_candidate, zbx_strerror(errno));
        break;  /* must return, situation could have changed */
    }

    *mtime = (int)file_buf.st_mtime;    /* must contain the latest mtime as possible */
    if (file_buf.st_size < *lastlogsize)
    {
        *lastlogsize = 0;   /* maintain backward compatibility */
    }

    if (-1 == (fd = zbx_open(logfile_candidate, O_RDONLY)))
    {
        zabbix_log(LOG_LEVEL_WARNING, "cannot open [%s]: %s", logfile_candidate, zbx_strerror(errno));
        break;  /* must return, situation could have changed */
    }

    if ((off_t)-1 != lseek(fd, (off_t)*lastlogsize, SEEK_SET))
    {
        if (-1 != (nbytes = zbx_read(fd, buffer, sizeof(buffer), encoding)))
        {
            if (0 != nbytes)
            {
                *lastlogsize += nbytes;
                *value = convert_to_utf8(buffer, nbytes, encoding);
                zbx_rtrim(*value, "\r\n ");
                ret = SUCCEED;
                break;  /* return at this point */
            }
            else    /* EOF is reached, but there can be other files to try reading from */
            {
                if (i == logfiles_num - 1)
                {
                    ret = SUCCEED;  /* EOF of the the most current file is reached */
                    break;
                }
                else
                {
                    zbx_free(logfile_candidate);
                    *lastlogsize = 0;
                    close(fd);
                    continue;   /* try to read from more current file */
                }
            }
        }
        else    /* cannot read from the file */
        {
            zabbix_log(LOG_LEVEL_WARNING, "cannot read from [%s]: %s",
                    logfile_candidate, zbx_strerror(errno));
            break;  /* must return, situation could have changed */
        }
    }
    else    /* cannot position in the file */
    {
        zabbix_log(LOG_LEVEL_WARNING, "cannot set position to [%li] for [%s]: %s",
                *lastlogsize, logfile_candidate, zbx_strerror(errno));
        break;  /* must return, situation could have changed */
    }
}   /* trying to read from logfiles */

forループ内でここまでで決めたインデックスiを使って、logfiles[i]以降にあるログファイル全てを読みにいこうとしています。つまり、ログローテーションしてmessagesがmessages.1になった場合、先にmessages.1の残りの部分を読んでから、新しいmessagesファイルを読みに行こうとします。

その後にあるファイル情報の取得、lastlogsizeの処理、64KBづつログファイルを読み込んでutf8変換などの処理はlog[]キーと同様です。少し異なるのは、ファイルのmtimeを変数に保存しておいたり、ファイルの末尾まで読んだときにlogfiles配列に次のファイルが残っていたら、続けて次のファイルを先頭から(lastlogsize=0)読もうとする点です。

valueに読み込まれた文字、lastlogsizeの値の処理はlog[]キーと同様に処理されます。logrt[]の場合はmtimeもlastlogsizeと同様にactive_metrics配列に保存されます。

時刻: 19:24:00
ラベル:

0 件のコメント:

コメントを投稿

登録: コメントの投稿 (Atom)