tl;dr

  • Amazon Aurora のスロークエリログを Logstash を使って Amazon ES に放り込みたい
  • サーバーレスでやりたい場合には Lambda を利用する方法が既に紹介されている
  • 今回はあえて logstash を使う

メモ

参考

Aurora のスロークエリログについて

ファイルに吐く場合に以下のような挙動となるようだ。

  • slow_query_log を ON にすると一時間に一回 mysql-slowquery.log.YYYY-MM-DD.HH というログが生成される
  • general_log を ON にすると mysql-slowquery.log というログが生成されてリアルタイムに確認出来る

今回は一時間に一回 cron でスロークエリログを API で取得して logstash 経由で Amazon ES に放り込むことにする。

試した構成

20161022145115

試す環境

$ cat /etc/redhat-release 
CentOS release 6.8 (Final)

$ python -V
Python 2.6.6

$ /opt/logstash/bin/logstash --version
logstash 2.4.0

$ sudo /opt/logstash/bin/plugin list --installed --verbose logstash-output-amazon_es
logstash-output-amazon_es (1.0)

logstash のインストール

$ sudo yum install -y java-1.8.0-openjdk.x86_64
$ sudo rpm --import https://packages.elastic.co/GPG-KEY-elasticsearch
$ sudo sh -c 'cat > /etc/yum.repos.d/logstash.repo
[logstash-2.4]
name=Logstash repository for 2.4.x packages
baseurl=https://packages.elastic.co/logstash/2.4/centos
gpgcheck=1
gpgkey=https://packages.elastic.co/GPG-KEY-elasticsearch
enabled=1
EOT'
$ sudo yum install -y logstash

logstash の Amazon ES プラグインの導入

$ cd /opt/logstash
$ sudo bin/plugin install logstash-output-amazon_es

以下のように出力される。

The use of bin/plugin is deprecated and will be removed in a feature release. Please use bin/logstash-plugin.
OpenJDK 64-Bit Server VM warning: If the number of processors is expected to increase from one, then you should configure the number of parallel GC threads appropriately using -XX:ParallelGCThreads=N
Validating logstash-output-amazon_es
Installing logstash-output-amazon_es
Installation successful

SDK を利用してスロークエリログを取得する


#!/usr/bin/env python
# -*- coding: utf-8 -*-

import boto3
import sys
import re
from pytz import timezone
from datetime import datetime

# DB 名を指定
DBINSTANCEIDENTIFIER = 'oreno-aurora'

# 不要な行
LINES = [
    "/rdsdbbin/oscar/bin/mysqld, Version: 5.6.10-log (MySQL Community Server (GPL)). started with:",
    "Tcp port: 3306  Unix socket: /tmp/mysql.sock",
    "Time                 Id Command    Argument"
]

# 取得するログファイルの日付を生成
LOGDATETIME = datetime.now(timezone('UTC')).strftime("%Y-%m-%d.%H")

# RDS への接続
rds = boto3.client('rds', region_name='ap-northeast-1')

# ログの取得
try:
    body = rds.download_db_log_file_portion(
            DBInstanceIdentifier = DBINSTANCEIDENTIFIER,
            LogFileName = 'slowquery/mysql-slowquery.log.' + LOGDATETIME,
    )['LogFileData']
except Exception as e:
    print {'result': 'error', 'description': e}
    sys.exit (1)

# 取得したログを一行ずつ展開(LINES に含まれる行と ^# Time: にマッチする行を削除)
for line in body.split("\n"):
    if not line or line in LINES or re.match("^# Time:" , line):
        continue
    else:
        print line

EC2 に DownloadDBLogFilePortion ポリシーをアタッチする

既に適用済みの IAM role に DownloadDBLogFilePortion ポリシーをアタッチする。

{
    "Version": "2012-10-17",
    "Statement": [
        {
            "Sid": "RDSSlowLogDownloadPolicy",
            "Action": [
                "rds:DownloadDBLogFilePortion"
            ],
            "Effect": "Allow",
            "Resource": "*"
        }
    ]
}

試しにログを出力させてみる。

$ python rds-slow-log.py
# User@Host: xxxxxxx[xxxxxxx] @  [xx.x.x.xxx]  Id:     6
# Query_time: 7.000184  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 0
SET timestamp=1477110716;
SELECT SLEEP(7);

(snip)

# User@Host: xxxxxxx[xxxxxxx] @  [xx.x.x.xxx]  Id:    48
# Query_time: 8.000187  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 0
SET timestamp=1477112288;
SELECT SLEEP(8);
# User@Host: xxxxxxx[xxxxxxx] @  [xx.x.x.xxx]  Id:    49
# Query_time: 11.000176  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 0
SET timestamp=1477112330;
SELECT SLEEP(11);
# User@Host: xxxxxxx[xxxxxxx] @  [xx.x.x.xxx]  Id:    50
# Query_time: 6.000193  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 0
SET timestamp=1477112366;
SELECT SLEEP(6);

logstash の設定

# input
input {
  stdin {
    codec => multiline {
      pattern => "^# User@Host:"
      negate => true
      what => previous
    }
  }
}

# filter
filter {
  grok {
    match => [ "message", "^# User@Host: %{USER:user}(?:\[[^\]]+\])?\s+@\s+\[%{IP:client}?\]\s+Id:\s+%{NUMBER:client_id:int}\n# Query_time: %{NUMBER:duration:float}\s*Lock_time: %{NUMBER:lock_wait:float}\s*Rows_sent: %{NUMBER:rows_sent:int}\s*Rows_examined: %{NUMBER:rows_examined:int}\nSET timestamp=%{NUMBER:timestamp};\n%{GREEDYDATA:sql_query};"]
  }

  date {
    match => [ "timestamp", "UNIX" ]
  }

}

# output
output {
  # for Debug
  # stdout { codec => json }
  amazon_es {
    hosts => ["search-xxxxxxxxx.ap-northeast-1.es.amazonaws.com"]
    region => "ap-northeast-1"
    index => "rds_slow_log-%{+YYYY.MM.dd}"
  }
  file {
    path => "/path/to/rds_slow_log-%{+YYYY-MM-dd-HH}.json"
  }
}

cron で実行

以下のようなラッパースクリプトを作成。

#!/usr/bin/env bash

_LOG_DATE_TIME=$(date +%Y-%m-%d_%H)
_DELETE_LOG_DATE=$(date --date '7 day ago' +%Y-%m-%d)

_ROOT="/path/to/rds-slow-log"
_LOGSTASH_CONF="rds-slow-log.conf"
_LOGSTASH_LOG="rds-slow-log.log"

ls ${_ROOT}/${_LOGSTASH_LOG}.${_DELETE_LOG_DATE}_* >/dev/null 2>&1
[ $? -eq 0 ] && rm -f ${_ROOT}/${_LOGSTASH_LOG}.${_DELETE_LOG_DATE}_*

${_ROOT}/bin/rds-slow-log.py | \
  /opt/logstash/bin/logstash \
    -f ${_ROOT}/conf/${_LOGSTASH_CONF} \
    -l ${_ROOT}/log/${_LOGSTASH_LOG}.${_LOG_DATE_TIME}

cron は以下のように設定。

3 * * * *    /path/to/rds-slow-log/bin/run.sh >/dev/null 2>&1

EC2 に Amazon ES へデータをポストする為のポリシーをアタッチする

既に適用済みの IAM role に ESHttpPost ポリシーをアタッチする。

{
    "Version": "2012-10-17",
    "Statement": [
        {
            "Effect": "Allow",
            "Action": "es:ESHttpPost",
            "Resource": "arn:aws:es:*:*:*"
        }
    ]
}

ダミーのクエリを仕込む

以下のようなスクリプトであえてスロークエリが発生するようにする。

while true;
do
  sleep 30
  TIME=`awk 'BEGIN{srand();print int(rand() * 15)}'`
  MYSQL_PWD="xxxxxxxxxxxx" mysql -udbadmin -h oreno-aurora-1.cluster-xxxxxxxxxxxxxx.ap-northeast-1.rds.amazonaws.com --execute "SELECT SLEEP(${TIME});"
done

しばらくすると…

Kibana からスロークエリログが確認出来るようになる。
20161022145136
マッピングは適宜設定する必要がある。

以上

  • メモでした
  • 久し振りに Logstash を触った（改めて勉強し直したい）

元記事はこちら

「Amazon Aurora のスロークエリログを logstash を使って Amazon ES に放り込む」