[Prometheus] 自作mtailでログ監視

## 目次
- [[目次] Prometheusで監視システムを作る with Docker](https://qiita.com/Esfahan/items/7dc780501f418a71ad9d)

## 概要
Prometheusでログ監視をするための環境構築手順。mtailというGoogleが用意しているログパースツールを利用する。mtailのルールを自作する方法についても説明する。

mtailの簡易検証用の環境はこちら
https://github.com/Esfahan/prometheus-and-mtail

## 前提条件
以下の手順でPrometheus環境を構築していることを前提とする。
https://qiita.com/Esfahan/items/0feaedfd771f49ac7ee4

## mtail
こちらを利用する。
https://github.com/google/mtail

## 環境
- mtail v3.0.0-rc46

## とりあえず動かしてみる
### Docker
監視対象のサーバーで立ち上げる。/var/log/messagesと/var/log/cronのメトリクスを収集し、ログの行数をカウントするだけのサンプル。

mtail公式が用意している[linecount.mtail](https://github.com/google/mtail/blob/main/examples/linecount.mtail)というルールを利用する。

自作のルールでメトリクス収集する方法は[後述](#自作のmtailでメトリクス収集する)する。

```yaml:docker-compose.yaml
version: '3'
services:
  mtail:
    image: dylanmei/mtail
    container_name: mtail
    hostname: mtail
    volumes:
      - /var/log/:/var/log/
    ports:
      - 3903:3903
    entrypoint:
           - mtail
           -  --progs
           -  /go/src/github.com/google/mtail/examples/linecount.mtail
           -  --logs
           -  /var/log/messages
           -  --logs
           -  /var/log/cron
```

```console
$ sudo docker-compose up -d --build
```

## Prometheusの設定
[こちらの記事](https://qiita.com/Esfahan/items/0feaedfd771f49ac7ee4)で構築したPrometheus環境の設定ファイルを編集する。

### 監視対象を追加
prometheus.yamlに以下を追記。

```diff:prometheus/prometheus.yaml
# 前略
scrape_configs:
+  - job_name: mtail
+    metrics_path: /mtail/metrics
+    static_configs:
+      - targets:
+        - your_mtail_server.com:3903
+        labels:
+          env: development
```

### MtailのUI
http://your_mtail_server.com:3903
![68747470733a2f2f71696974612d696d6167652d73746f72652e73332e61702d6e6f727468656173742d312e616d617a6f6e6177732e636f6d2f302f3130353933362f33613033616438342d323736382d633932352d646364642d3239653638386265333362312e706e67.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105936/5c2d40c9-3bad-aff8-64ef-62937235d98f.png)

prometheusというリンクをクリックすると、メトリクスが見れる。

```prometheus
# TYPE line_count counter
# line_count defined at linecount.mtail:4:9-18
line_count{prog="linecount.mtail"} 244
```

### PrometheusのUI
赤枠のアイコンをクリックする
![Screen Shot 2021-06-10 at 17.40.51.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105936/98819e4b-f116-8a88-bf50-8590934449f8.png)

mtailと通信できていれば、「line_count」というメトリクスが表示される。
![Screen Shot 2021-06-10 at 17.41.04.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105936/2d3c6767-c36a-03cd-f25b-4ccbdeee07b5.png)

### PromQL
line_countと入力すると、以下のような結果が得られる。ログの行数が表示されている。
![Screen Shot 2021-06-10 at 17.57.22.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105936/3cd15809-cfaa-636d-78c2-add04fa06ff8.png)

## 自作のmtailでメトリクス収集する
独自のルールでメトリクス収集するため、mtailを自作する。
今回の例では、example.logに出力されたログを、正規表現でカウントするもの、特定の文字列が含まれているかどうかを判別するmtailを作る。

mtailの文法については以下で説明されている。
https://github.com/google/mtail/blob/main/docs/Language.md

また、mtailのサンプルは以下に用意されている。
https://github.com/google/mtail/tree/main/examples

### ディレクトリ構成
以下のディレクトリ構成を作る。

```bash
├── docker-compose.yaml
├── logs
│   └── example.log # メトリクス収集対象のログ
└── mtail
    └── example.mtail # 自作mtail
```

事前準備

```console
$ mkdir {logs,mtail}
$ touch logs/example.log
```

### example.mtail
mtail/example.mtailを作成する。どういうルールでメトリクス収集するのかはコメントアウトを参照。

変数定義をする際、counterかgaugeのどちらかのtypeを定義する。
counterは、正規表現にマッチした行数をカウントするときに使う。
gaugeは数値、文字列などを代入できるtypeで、以下の例では、正規表現にマッチした行があれば`1`を、なければ`0`を返すルールとなっている。`0`, `1`でなく、文字列を返すことも可能。文字列の場合シングルクォートだとエラーになるのでダブルクォートにすること。`line_count_info` や `warn_flg_no_declared` は変数名だが、任意の名前でよい。

```lang:mtail/example.mtail
counter line_count_error
counter line_count_fatal
counter line_count_debug

gauge error_flg_syntax
gauge fatal_flg_oom
gauge debug_flg

# [ERROR]の行が何行あるか
/^\[ERROR/ {
  line_count_error++
}

# [FATAL]の行が何行あるか
/^\[FATAL/ {
  line_count_fatal++
}

# [DEBUG]の行が何行あるか
/^\[DEBUG/ {
  line_count_debug++
}

# "Syntax error"を含む行があるかどうか
/Syntax error/ {
  error_flg_syntax = 1
}

# "Out of memory"を含む行があるかどうか
/Out of memory/ {
  fatal_flg_oom = 1
}

# "debug message"を含む行があるかどうか
/debug message/ {
  debug_flg = 1
}
```


ちなみに、golangでは正規表現で「文字列がマッチしない場合」という否定ができないので、工夫する必要がある。以下参照。

https://qiita.com/Esfahan/items/b22c2b026dfab454ca96

### Dockerでmtailの環境を構築

```yaml:docker-compose.yaml
version: '3'
services:
  mtail:
    image: dylanmei/mtail
    container_name: mtail
    volumes:
      - ./logs:/logs/
      - ./mtail/:/mtail
    ports:
      - 3903:3903
    entrypoint:
           - mtail
           -  --progs
           -  /mtail/example.mtail
           -  --logs
           -  /logs/example.log

           #######################
           # 複数ファイル指定する場合
           #######################
           #- mtail
           #-  --progs
           # progsはディレクトリを指定することで、その配下のファイルが全て読み込まれる
           #-  /mtail/
           # logsは、以下の様にカンマ区切りで指定するか、もしくは--logsを複数指定することでも可能。
           #-  --logs
           #-  /logs/example.log,/logs/example02.log
           #-  --logs
           #-  /logs/example03.log
    networks:
      - sample-network

networks:
    sample-network:
        external: true
```

```console
$ sudo docker-compose up -d --build mtail
```

### mtailの文法エラーなどの確認方法
ブラウザからエラーを確認できる。
http://your_mtail_server.com:3903
![Screen Shot 2021-06-12 at 20.01.16.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105936/a45d9726-263d-79b8-828c-8308fa6f40c2.png)

エラーがない場合
![Screen Shot 2021-06-12 at 20.06.36.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105936/ed54dc94-f55d-eefe-8ad7-5d80d4419d7a.png)


### 対象ログ
logs/example.logに以下を書き込む。
Dockerコンテナが起動した後から出力されたログが収集されるので、docker-compose upをした後にログを書き込む。

```text:logs/example.log
[INFO]  This is an info message.
[WARN]  This is a warning message.
[WARN]  No declared value.
[ERROR] This is an error message.
[ERROR] Syntax error.
[ERROR] Syntax error.
[FATAL] This is a fatal message.
[FATAL] Out of memory.
[FATAL] Disk error.
[FATAL] Kernel panic.
```

### メトリクスをPrometheusの画面で確認
しばらくしてからPrometheusの画面を確認すると、メトリクス収集されていることが確認できる。
http://your_prometheus_server.com:9090/graph
![Screen Shot 2021-06-13 at 20.10.01.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105936/8e8d982a-c0dc-4042-847f-353fdf855b54.png)
![Screen Shot 2021-06-13 at 20.10.09.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105936/ec61ab4c-824c-9aff-c8e7-a1545a1bed62.png)
![Screen Shot 2021-06-13 at 20.10.17.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105936/6b1073c2-d80d-fa86-e3e4-da14f2ab15dd.png)

| 収集項目 | PromQL | 結果 |
| --- | --- | --: |
| [ERROR]の行が何行あるか | line_count_error | 3 |
| [FATAL]の行が何行あるか | line_count_fatal | 4 |
| [DEBUG]の行が何行あるか | line_count_debug | 0 |
| "Syntax error"を含む行があるかどうか | error_flg_syntax | 1 |
| "Out of memory"を含む行があるかどうか | fatal_flg_oom | 1 |
| "debug message"を含む行があるかどうか | debug_flg | Empty |


## 障害検知、復旧の検証
### example.mtailにルール追加
先程作成したexample.mtailでは、"Out of memory"を含む行がある場合に`fatal_flg_oom = 1`となるルールを作成した。ここではそれに加えて、"Memory recorverd"を含む行がある場合に`fatal_flg_oom = 0`となるルールを追記する。

こうすることで、ログに"Out of memory"が書き込まれたら障害発生、"Memory recorverd"が書き込まれたら復旧、という挙動にすることができる。

```diff:mtail/example.mtail
gauge fatal_flg_oom

# "Out of memory"を含む行があるかどうか
/Out of memory/ {
  fatal_flg_oom = 1
}

+# 以下を追記
+# "Memory recorverd"を含む行があるかどうか
+/Memory recorverd/ {
+  fatal_flg_oom = 0
+}
```

設定反映

```console
$ sudo docker-compose restart mtail
```


### 検証
"Out of memory"をログに追記する。

```console
$ echo "[FATAL] Out of memory." >> logs/example.log
```

`fatal_flg_oom` が `1`になったことを確認。
http://your_prometheus_server.com:9090/graph
![Screen Shot 2021-06-13 at 18.04.07.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105936/0acbb3af-b75d-cc79-0894-30f36b60b9da.png)


"Memory recorverd"をログに追記する。

```console
$ echo "[INFO] Memory recorverd" >> logs/example.log
```

`fatal_flg_oom` が `0`になったことを確認。
http://your_prometheus_server.com:9090/graph
![Screen Shot 2021-06-13 at 18.04.37.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105936/dcd518e4-9942-2a33-cf3e-59fa805ce196.png)

再度`[FATAL] Out of memory.`が書き込まれればまた`fatal_flg_oom = 1`となり、`[INFO] Memory recorver`が書き込まれれば`fatal_flg_oom = 0`となるので何度か試してみるとよい。

## ログにERRORという文字列が書き込まれたらエラー検知をする例
### mtail
ERRORという文字列がログに書き込まれたらerror_countがカウントUPされるルールを作る。

mtail/mtail/example.mtail

```
counter error_count

/ERROR/ {
  error_count++
}
```

### log
ログにERRORという文字が書き込む。

```
[ERROR] Syntax error.
```

### 検知方法（PromQL）
rate関数で直近1分にERRORという文字列が書き込まれたかを確認する。
書き込まれていなければ`0`を返すので、以下のPromQLでエラー検知できる。

```prometheus:直近1分の場合
rate(error_count[1m]) > 0
```

```prometheus:直近5分の場合
rate(error_count[5m]) > 0
```

rate関数については以下を参照。
参考：[rate関数](https://qiita.com/Esfahan/items/2b8f8763b648d8bb3eb9#rate%E9%96%A2%E6%95%B0)

## mtailコマンドでメトリクス確認
以下のようにmtailコマンドに`--one_shot` というオプションを付けて実行することで、メトリクスを確認する事もできる。

```yaml:docker-compose.yaml
version: '3'
services:
  mtail-checker:
    image: dylanmei/mtail
    container_name: mtail-checker
    hostname: mtail-checker
    volumes:
      - ./logs:/logs/
      - ./mtail/:/mtail
    entrypoint:
           - mtail
           -  --one_shot
           -  --progs
           -  /mtail/example.mtail
           -  --logs
           -  /logs/example.log
```

```console
$ sudo docker-compose run --rm mtail-checker
Creating mtail_mtail-checker_run ... done
```

```json
Metrics store:{
  "debug_flg": [
    {
      "Name": "debug_flg",
      "Program": "example.mtail",
      "Kind": 2,
      "Type": 0
    }
  ],
  "error_flg_syntax": [
    {
      "Name": "error_flg_syntax",
      "Program": "example.mtail",
      "Kind": 2,
      "Type": 0,
      "LabelValues": [
        {
          "Value": {
            "Value": 1,
            "Time": 1623583432182670126
          }
        }
      ]
    }
  ],
  "fatal_flg_de": [
    {
      "Name": "fatal_flg_de",
      "Program": "example.mtail",
      "Kind": 2,
      "Type": 0,
      "LabelValues": [
        {
          "Value": {
            "Value": 1,
            "Time": 1623583432182861408
          }
        }
      ]
    }
  ],
  "fatal_flg_kp": [
    {
      "Name": "fatal_flg_kp",
      "Program": "example.mtail",
      "Kind": 2,
      "Type": 0,
      "LabelValues": [
        {
          "Value": {
            "Value": 1,
            "Time": 1623583432182882874
          }
        }
      ]
    }
  ],
  "fatal_flg_oom": [
    {
      "Name": "fatal_flg_oom",
      "Program": "example.mtail",
      "Kind": 2,
      "Type": 0,
      "LabelValues": [
        {
          "Value": {
            "Value": 1,
            "Time": 1623583432182722713
          }
        }
      ]
    }
  ],
  "line_count_debug": [
    {
      "Name": "line_count_debug",
      "Program": "example.mtail",
      "Kind": 1,
      "Type": 0,
      "LabelValues": [
        {
          "Value": {
            "Value": 0,
            "Time": 0
          }
        }
      ]
    }
  ],
  "line_count_error": [
    {
      "Name": "line_count_error",
      "Program": "example.mtail",
      "Kind": 1,
      "Type": 0,
      "LabelValues": [
        {
          "Value": {
            "Value": 3,
            "Time": 1623583432182657661
          }
        }
      ]
    }
  ],
  "line_count_fatal": [
    {
      "Name": "line_count_fatal",
      "Program": "example.mtail",
      "Kind": 1,
      "Type": 0,
      "LabelValues": [
        {
          "Value": {
            "Value": 4,
            "Time": 1623583432182874744
          }
        }
      ]
    }
  ],
  "line_count_info": [
    {
      "Name": "line_count_info",
      "Program": "example.mtail",
      "Kind": 1,
      "Type": 0,
      "LabelValues": [
        {
          "Value": {
            "Value": 1,
            "Time": 1623583432182384349
          }
        }
      ]
    }
  ],
  "line_count_warn": [
    {
      "Name": "line_count_warn",
      "Program": "example.mtail",
      "Kind": 1,
      "Type": 0,
      "LabelValues": [
        {
          "Value": {
            "Value": 2,
            "Time": 1623583432182542428
          }
        }
      ]
    }
  ],
  "warn_flg_no_declared": [
    {
      "Name": "warn_flg_no_declared",
      "Program": "example.mtail",
      "Kind": 2,
      "Type": 0,
      "LabelValues": [
        {
          "Value": {
            "Value": 1,
            "Time": 1623583432182558035
          }
        }
      ]
    }
  ]
}
```

## その他Exporterの利用方法
- [MySQL Exporter with Docker](https://qiita.com/Esfahan/items/ccd0b09a681da0b7cb85)
- [Postgres Exporter with Docker](https://qiita.com/Esfahan/items/08d0c1ff94710603bac9)