はじめに

あとで Kibana で遊ぶために Logstash を使って Elasticsearch へデータを投入するついでに、どのぐらいのデータをどれぐらいの時間で投入できるものなのか？を興味本位で確認。ちなみに結論から書いておくと 23 分弱で完了。

実行環境

MacにDocker入れて、その上でLogstashもElasticsearchもコンテナで稼働。

PC
- MacBook Air (13-inch, Early 2015)
- macOS High Sierra バージョン 10.13.3
- プロセッサ 1.6 GHz Intel Core i5
- メモリ 8 GB 1600 MHz DDR3
Docker Version 18.03.0-ce-mac59 (23608)
Elasticsearch 6.2.3
Logstash 6.2.3

Elasticsearch 6.2.3 のセットアップ

これまで使っていたものがすこし古くなってきたので作業時点で最新のものを取得。

$ docker pull docker.elastic.co/elasticsearch/elasticsearch:6.2.3

取得したイメージからコンテナを実行、する前に Elasticsearch と Logstash、Kibana あたりをつなげるためにネットワークを作成。

$ docker network create elasticnw

作成したネットワークにコンテナをぶら下げる --net オプションを追加してコンテナを実行。

$ docker run -dti -h elasticsearch --name elasticsearch -p 9200:9200 -p 9300:9300 -e "discovery.type=single-node" --net elasticnw docker.elastic.co/elasticsearch/elasticsearch:6.2.3 /bin/bash

Elasticsearch のコンテナは attach して入るとデフォルト root ユーザだけど root では Elasticsearch を実行できない、という罠が仕掛けてある上にいちいち起動コマンドを手入力するのも面倒なので簡易起動スクリプトを作成。パスの通った場所に置いておきたかったので乱暴だけど elasticsearch ホーム配下の bin の下に設置。

/usr/share/elasticsearch/bin/esstart

#!/bin/bash

#--------------------------------------------------
# elasticsearch startup shell
#--------------------------------------------------

ELASTIC_HOME="/usr/share/elasticsearch"

su - elasticsearch -c $ELASTIC_HOME/bin/elasticsearch > $ELASTIC_HOME/logs/elastic.log &

起動ログが落ち着いたらホストOSから疎通確認。

$ curl -s http://localhost:9200
{
  "name" : "pBmvODk",
  "cluster_name" : "docker-cluster",
  "cluster_uuid" : "7QL3pMI6T2SLyxc22KdYxg",
  "version" : {
    "number" : "6.2.3",
    "build_hash" : "c59ff00",
    "build_date" : "2018-03-13T10:06:29.741383Z",
    "build_snapshot" : false,
    "lucene_version" : "7.2.1",
    "minimum_wire_compatibility_version" : "5.6.0",
    "minimum_index_compatibility_version" : "5.0.0"
  },
  "tagline" : "You Know, for Search"
}

疎通OK。次はLogstash。

Logstashのセットアップ

Logstashもコンテナでセットアップ。-v でホストOSのディレクトリをマウント、--net で Elasticsearch と同じネットワークにぶら下げる。コンテナ起動したら attach して入る。

$ docker pull docker.elastic.co/logstash/logstash:6.2.3
$ docker run -dti -h logstash --name logstash -v /work/data/logstash:/data --net elasticnw docker.elastic.co/logstash/logstash:6.2.3 /bin/bash
$ docker attach logstash

今回扱うデータは Apache HTTP Server の common 形式の accesslog なので以下 conf ファイルを作成する。置き場所はとりあえず Logstash ホーム下の config へ。なぜ index 名が nasa なのかというと、大量ログデータのサンプルをネットで探していたら1995年7月・8月におけるNASAのWWWへのアクセスログという年代モノが公開されていてそれを使用したから。ここにひっそり書いてあった。

/usr/share/logstash/config/accesslog.conf

input {
  file {
    path => "/data/access_log_*"
    start_position => "beginning"
    sincedb_path => "/dev/null"
  }
}

filter {
  if [path] =~ "access" {
    mutate { replace => { "type" => "apache_access" } }
    grok {
      match => { "message" => "%{COMMONAPACHELOG}" }
    }
  }
  date {
    match => [ "timestamp" , "dd/MMM/yyyy:HH:mm:ss Z" ]
  }
}

output {
    elasticsearch {
        hosts => [ "elasticsearch" ]
        index => "nasa"
    }
}

ダウンロードしたデータをホストOSのデータフォルダに配置。

$ mv ~/Downloads/access_log_*95 /work/data/logstash
$ cd /work/data/logstash
$ ls -l
-rw-r--r--@ 1 xxxx@xxxx  staff  167813770  4 16 17:18 access_log_Aug95
-rw-r--r--@ 1 xxxx@xxxx  staff  205242368  4 16 17:17 access_log_Jul95

コンテナ側でも確認、ちゃんとある。全部で約 346 万行。ファイルの時刻が微妙にズレてるのはコンテナの時刻がUTCのままだから。

logstash

bash-4.2$ ls -l /data
total 364316
-rw-r--r-- 1 logstash logstash 167813770 Apr 16 08:18 access_log_Aug95
-rw-r--r-- 1 logstash logstash 205242368 Apr 16 08:17 access_log_Jul95
bash-4.2$ wc -l access_log_*
  1569898 access_log_Aug95
  1891714 access_log_Jul95
  3461612 total

以上でログの準備まで完了。

簡易計測スクリプトの準備

なんかもっといいやり方がある気もするけど Elasticsearch へ index 内のドキュメント数のカウントを 1 秒おきに問い合わせるスクリプトを作成。

countesdocs.sh

#!/bin/sh

ESURL="http://localhost:9200"

if [ $# == 0 ]
then
  echo
  echo "usage: $0 INDEX"
  echo
  exit 1
else
  INDEX_NAME=$1
fi

while true
do
  echo `date +[%Y/%m/%d" "%T]` `curl -s $ESURL/$INDEX_NAME/_count`
  sleep 1
done

exit 0

権限の設定も忘れずに。

$ chmod 755 countesdocs.sh

計測の実行

Logstash と計測スクリプトを同時に実行。計測スクリプトはホストOSで実行、出力ログを tail で眺める。

logstash

bash-4.2$ logstash -f /usr/share/logstash/config/accesslog.conf

HostOS

$ ./countesdocs.sh nasa > logstash_nasa.log &
$ tail -f logstash_nasa.log

データ投入が始まるのは Logstash 実行 1 分後ぐらい。

logstash_nasa.log

[2018/04/17 10:50:27] {"error":{"root_cause":[{"type":"index_not_found_exception","reason":"no such index","resource.type":"index_or_alias","resource.id":"nasa","index_uuid":"_na_","index":"nasa"}],"type":"index_not_found_exception","reason":"no such index","resource.type":"index_or_alias","resource.id":"nasa","index_uuid":"_na_","index":"nasa"},"status":404}
[2018/04/17 10:50:28] {"error":{"root_cause":[{"type":"index_not_found_exception","reason":"no such index","resource.type":"index_or_alias","resource.id":"nasa","index_uuid":"_na_","index":"nasa"}],"type":"index_not_found_exception","reason":"no such index","resource.type":"index_or_alias","resource.id":"nasa","index_uuid":"_na_","index":"nasa"},"status":404}
[2018/04/17 10:50:29] {"error":{"root_cause":[{"type":"index_not_found_exception","reason":"no such index","resource.type":"index_or_alias","resource.id":"nasa","index_uuid":"_na_","index":"nasa"}],"type":"index_not_found_exception","reason":"no such index","resource.type":"index_or_alias","resource.id":"nasa","index_uuid":"_na_","index":"nasa"},"status":404}

--- 中略 ---

[2018/04/17 10:51:29] {"error":{"root_cause":[{"type":"index_not_found_exception","reason":"no such index","resource.type":"index_or_alias","resource.id":"nasa","index_uuid":"_na_","index":"nasa"}],"type":"index_not_found_exception","reason":"no such index","resource.type":"index_or_alias","resource.id":"nasa","index_uuid":"_na_","index":"nasa"},"status":404}
[2018/04/17 10:51:30] {"count":0,"_shards":{"total":5,"successful":4,"skipped":0,"failed":0}}
[2018/04/17 10:51:31] {"count":668,"_shards":{"total":5,"successful":5,"skipped":0,"failed":0}}

冒頭で記載のとおり開始（10:50:27）から約 23 分弱で投入完了（11:12:52）。ちゃんと集計してないけど秒あたり 2000〜4000 件投入できてるかんじ。CPUやメモリも監視してないけどこの程度のMacならこんなもんなのかな。