health checkを除外してCloudWatchのログを眺めたい。

## やりたいこと

表題の通りです。

### なぜ？

小さなシステムの動作チェックを担当した際に、ログ周りはCloudWatchに書き出されているので、手っ取り早くそちらを眺めました。
でも、health checkのログが多すぎて本来見たいログが埋もれてしまって悲しかった、というのが背景です...。

### 前提条件

- AWSの管理コンソールから見るのではなく、[awslogs](https://github.com/jorgebastida/awslogs)コマンドで手元のターミナルで見たい
- health checkっぽいのは除外したい
- health checkを叩いてくるのはロードバランサ (ELB）
- ヘルスチェックのログ出力自体は、まだ調整中なので抑止せずに書き出しておきたい（わがままで申し訳ないです...）
- **Filter options** (``--filter-pattern``) を使って絞り込む
  - https://github.com/jorgebastida/awslogs#filter-options
  - ただし、この場合は「**除外**」のフィルタ条件にしたい

## やってみる

Nginxのログっぽいもので試します。

- ただし、ログは実際のアプリケーションからのログではなく、シェルスクリプトでロググストリームに突っ込むという方式でテストします
  - [CloudWatchのロググループに手動でテスト用ログを投入したい。](https://qiita.com/akiko-pusu/items/d24ec8e1d61d03464e0d)

awslogsのコマンドラインオプションはこの通り。

- -S オプションは、出力行にロググループ名を添えない（長くなるので）
- -G オプションは、出力行にログストリーム名を添えない（長くなるので）
- awslogs get ``ロググループ名``  (ロググループ名まで指定の場合)
- awslogs get ``ロググループ名`` ``ログストリーム名``  (ログストリーム名まで指定の場合)

-----

**お試しデータのスクリーンショット**
<img width="600" alt="試しにつっこんだデータ.png" src="https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/27976/1d8e8dc1-60e0-1948-a51c-2bee7bd29723.png">
-----

### 実験: フィルタ無し

- CloudWatch上に ``/TestLogGroup`` というロググループを作成しています
- さらに、``TestStream`` というログストリームにログを書き出しています
- ``-s 1m`` で直近1分のものを出力します
 

```bash
$ awslogs get /TestLogGroup TestStream -s 1m --aws-region="ap-northeast-1"
/TestLogGroup TestStream 198.51.100.2 - - [2020-05-16T11:50:54+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
/TestLogGroup TestStream 192.0.2.10 - - [2020-05-16T11:50:56+0900] "GET /test/health_check HTTP/1.1" 200 25 "-" "ELB-HealthChecker/2.0" "-"
/TestLogGroup TestStream 198.51.100.2 - - [2020-05-16T11:50:58+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
/TestLogGroup TestStream 192.0.2.10 - - [2020-05-16T11:51:00+0900] "GET /test/health_check HTTP/1.1" 200 25 "-" "ELB-HealthChecker/2.0" "-"
/TestLogGroup TestStream 198.51.100.2 - - [2020-05-16T11:51:03+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
/TestLogGroup TestStream 192.0.2.10 - - [2020-05-16T11:51:05+0900] "GET /test/health_check HTTP/1.1" 200 25 "-" "ELB-HealthChecker/2.0" "-"
/TestLogGroup TestStream 198.51.100.2 - - [2020-05-16T11:51:07+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
/TestLogGroup TestStream 192.0.2.10 - - [2020-05-16T11:51:09+0900] "GET /test/health_check HTTP/1.1" 200 25 "-" "ELB-HealthChecker/2.0" "-"
/TestLogGroup TestStream 198.51.100.2 - - [2020-05-16T11:51:11+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
/TestLogGroup TestStream 192.0.2.10 - - [2020-05-16T11:51:13+0900] "GET /test/health_check HTTP/1.1" 200 25 "-" "ELB-HealthChecker/2.0" "-"
/TestLogGroup TestStream 198.51.100.2 - - [2020-05-16T11:51:15+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
....
```

### 実験: フィルタあり

``--filter-pattern='-"ELB-HealthChecker/2.0"'`` を添えて、ELBからのヘルスチェックを除外してみます。

ポイントは、 **-** (マイナス) で除外パターンを指定している点です。

```bash
awslogs get /TestLogGroup TestStream -s 1m --aws-region="ap-northeast-1" --filter-pattern='-"ELB-HealthChecker/2.0"'

# 結果が絞りこまれました！
/TestLogGroup TestStream 198.51.100.2 - - [2020-05-16T11:56:46+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
/TestLogGroup TestStream 198.51.100.2 - - [2020-05-16T11:56:50+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
/TestLogGroup TestStream 198.51.100.2 - - [2020-05-16T11:56:55+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
/TestLogGroup TestStream 198.51.100.2 - - [2020-05-16T11:56:59+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
/TestLogGroup TestStream 198.51.100.2 - - [2020-05-16T11:57:04+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
/TestLogGroup TestStream 198.51.100.2 - - [2020-05-16T11:57:08+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
/TestLogGroup TestStream 198.51.100.2 - - [2020-05-16T11:57:13+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
/TestLogGroup TestStream 198.51.100.2 - - [2020-05-16T11:57:18+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
/TestLogGroup TestStream 198.51.100.2 - - [2020-05-16T11:57:22+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
/TestLogGroup TestStream 198.51.100.2 - - [2020-05-16T11:57:28+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
```

### オプションを調整してスッキリさせてみる

ロググループがわかっている、ログストリームは明示していなくても該当のロググループ内の最新のイベントで確認するだけでいい場合は、

- -G (グループ名を表示しない）
- -S (ストリーム名を表示しない）


オプションでもう少しスッキリします。

```bash
$ awslogs get /TestLogGroup -s 1m --aws-region="ap-northeast-1" -S -G --filter-pattern='-"ELB-HealthChecker/2.0"'

198.51.100.2 - - [2020-05-16T12:03:49+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
198.51.100.2 - - [2020-05-16T12:03:54+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
198.51.100.2 - - [2020-05-16T12:03:59+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
```

## あらためて

さて、上記でやりたいこととやったことを書いてしまいましたが、後々のことを考えて、自分のためのメモを添えます。

### awslogsについて

``AWS CloudWatch logs for Humans™`` というキャッチコピーがリポジトリに書かれていますが、まさに大助かりです...。

- リポジトリ: https://github.com/jorgebastida/awslogs
- pythonで書かれいます

Issueやプルリクエストも多く、Pythonで書かれているし、基本は更新系でなくapiからの取得と出力なので、OSSの素材としても良さそう！

### 除外パターンを複数指定したり組み合わせる場合は？

基本はCloudWatchのフィルタパターンに対応した書き方で値を渡します。

- https://docs.aws.amazon.com/ja_jp/AmazonCloudWatch/latest/logs/FilterAndPatternSyntax.html

**/test/health_check, HealthCheck の双方を含むケースを除外**

- ``-`` (マイナス) をつけた条件を列挙します

```bash
--filter-pattern='-"/test/health_check" -"HealthCheck"'
```

**POSTを含むイベントを抽出したい場合**

```bash
--filter-pattern='POST'
```

**POSTを含むイベントのうち特定のエンドポイントは不要**

- 条件を列挙しますが、除外の条件は -"条件パターン" を添えます

```bash
--filter-pattern='"POST" -"/endpoint_to_ignore"'
```

**どれかのパターンを含むイベントを抽出したい場合**

- キーワードの前に``?``を添えます

```bash
--filter-pattern='?index ?health'
```

**どれかのパターンを含むイベントのうち、あるパターンは除外したい場合**

- ORの条件の後に、``-"除外パターン"`` を添えます
- 以下だと、index.html か /test/health_check　を含む行はヒットしますが、そのうち 12:05台のイベントは除外されます 

```bash
awslogs get /TestLogGroup -s 10m --aws-region="ap-northeast-1" -S -G -filter-pattern='?index ?health -"T12:05"'

# 出力例 (T12:05は除外)
.....
198.51.100.2 - - [2020-05-16T12:04:52+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
192.0.2.10 - - [2020-05-16T12:04:54+0900] "GET /test/health_check HTTP/1.1" 200 25 "-" "ELB-HealthChecker/2.0" "-"
198.51.100.2 - - [2020-05-16T12:04:58+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
198.51.100.2 - - [2020-05-16T12:06:02+0900] "GET /index.html HTTP/1.1" 200 512 "-" "Dummy-UserAgent/1.0" "-"
192.0.2.10 - - [2020-05-16T12:06:06+0900] "GET /test/health_check HTTP/1.1" 200 25 "-" "ELB-HealthChecker/2.0" "-"
.....
```

### aws cli (aws logs filter-log-events) ではどう？

aws cliでももちろん抽出できますが、除外のパターンはちょっとうまく試せず....
JSONで受けてからjqやgrepでフィルタするといいのかもしれません。

```bash
# aws logsだと結果はjsonなので、jqで整形
aws logs filter-log-events --log-group-name /TestLogGroup --filter-pattern "ELB" | jq '.events[] | .message'

.....

"192.0.2.10 - - [2020-05-16T12:06:35+0900] \"GET /test/health_check HTTP/1.1\" 200 25 \"-\" \"ELB-HealthChecker/2.0\" \"-\""
"192.0.2.10 - - [2020-05-16T12:06:41+0900] \"GET /test/health_check HTTP/1.1\" 200 25 \"-\" \"ELB-HealthChecker/2.0\" \"-\""
"192.0.2.10 - - [2020-05-16T12:06:46+0900] \"GET /test/health_check HTTP/1.1\" 200 25 \"-\" \"ELB-HealthChecker/2.0\" \"-\""
```


## そもそも書き出さないようにするには？

エンドポイントとしての機能は利用したいけど、そもそもログは書かなくてもいいのでは？というのもあると思います。
こんなやり方で対応できます。ほかにもいろいろあると思うので、今後試しつつ調整したいと思います。

- NginxやApacheといったWebサーバ側では、カスタムログの設定で nolog を指定してみる
- Railsでhealth check用のエンドポイントを持っている場合は、そのhealth checkのアクションに対してはログを出力しないように設定してみる
  - https://github.com/roidrage/lograge (gemのlogrageを追加してignore設定するとか)


以上、ちょっとしたログのメモでした。