Zenn
⏱️

Logstashのオプションによる起動時間の変動有無の確認

に公開
logstash
tech

はじめに

  • ログをElasticsearch(Elastic社)に取り込む際、データ加工に同社製のLogstashをよく使う
  • Logstashは起動に数〜数十秒を要する
    • PCスペック他、加工に用いるプラグインの読み込み数依存
  • そのため素で開発すると 実装 > 確認 > 修正 のサイクルが長い
  • 次の方法で起動時間を試す

結果

  • 方法ごと
    • 方法１：28%短縮した(平均8.6秒->6.2秒)
    • 方法２：自動リロード後の読み込み再開まで1秒前後
  • 結論
    • プラグインが自動リロードに対応していればJVMオプションによる高速化でなく自動リロードが効果的
      • 設定更新検知のインターバル(デフォルト3秒)はスペックが許すなら短くすれば良い
    • リロード非対応プラグインの場合、JVMオプションの利用を検討

実行環境

  • Ubuntu 22.04.5 LTS, メモリ32GB
  • Docker 28.0.4
  • Logstash 8.17.4

前提条件

  • パイプラインで使用するプラグインの量は本番想定ではなく動作確認の簡素なもの
  • 方法１と方法２で使用するプラグインは厳密に揃えない
    • 方法2の途中でリロード不可のプラグインに気づいて面倒だった
    • inputをstdinからfileへ変更
main.conf
input {
    # 方法1
    stdin {}

    # 方法2
    file {
        path => "/tmp/log.txt"
    }
}

filter {
}

output {
    stdout {}
}

試行内容

方法1 (JVMオプション指定)

概要

結果

設定 最小時間 (秒) 最大時間 (秒) 平均時間 (秒) 標準偏差 (秒)
オプションなし 8.005 8.928 8.586 0.275
オプションあり 5.947 6.369 6.171 0.143
試行結果詳細
--------------------------------------------------
測定中: 1. オプションなし
Dockerイメージ: docker.elastic.co/logstash/logstash:8.17.4
JVM オプション: なし
--------------------------------------------------
  実行 1/10... 完了 (8.005 秒)
  実行 2/10... 完了 (8.407 秒)
  実行 3/10... 完了 (8.421 秒)
  実行 4/10... 完了 (8.500 秒)
  実行 5/10... 完了 (8.877 秒)
  実行 6/10... 完了 (8.583 秒)
  実行 7/10... 完了 (8.818 秒)
  実行 8/10... 完了 (8.928 秒)
  実行 9/10... 完了 (8.599 秒)
  実行 10/10... 完了 (8.726 秒)

--- 結果 ---
試行回数: 10
最小時間: 8.005 秒
最大時間: 8.928 秒
平均時間: 8.586 秒
標準偏差: 0.275
--------------------------------------------------

--------------------------------------------------
測定中: 2. オプションあり
Dockerイメージ: docker.elastic.co/logstash/logstash:8.17.4
JVM オプション: -Djruby.compile.invokedynamic=false -Djruby.compile.mode=OFF -XX:+TieredCompilation -XX:TieredStopAtLevel=1
--------------------------------------------------
  実行 1/10... 完了 (6.284 秒)
  実行 2/10... 完了 (6.011 秒)
  実行 3/10... 完了 (6.369 秒)
  実行 4/10... 完了 (6.199 秒)
  実行 5/10... 完了 (6.009 秒)
  実行 6/10... 完了 (6.326 秒)
  実行 7/10... 完了 (6.212 秒)
  実行 8/10... 完了 (6.227 秒)
  実行 9/10... 完了 (6.127 秒)
  実行 10/10... 完了 (5.947 秒)

--- 結果 ---
試行回数: 10
最小時間: 5.947 秒
最大時間: 6.369 秒
平均時間: 6.171 秒
標準偏差: 0.143
--------------------------------------------------

方法2 (自動リロード)

概要

  1. Logstash起動時のオプションに--config.reload.automaticを指定
  2. リロード開始のログ出力と(ほぼ)同時に取り込みデータ追加
  3. データ追加から処理までの時間を確認
    ※ 測定の自動化が手間だったので手動で3回確認
Logstash実行ログ
[2025-03-30T06:16:51,227][INFO ][logstash.pipelineaction.reload] Reloading pipeline {"pipeline.id"=>:main}
[2025-03-30T06:16:51,227][INFO ][filewatch.observingtail  ] QUIT - closing all files and shutting down.
##########
### このあたりで/tmp/log.txtにデータ追加
##########
[2025-03-30T06:16:51,402][INFO ][logstash.javapipeline    ][main] Pipeline terminated {"pipeline.id"=>"main"}
[2025-03-30T06:16:52,270][INFO ][logstash.javapipeline    ] Pipeline `main` is configured with `pipeline.ecs_compatibility: v8` setting. All plugins in this pipeline will default to `ecs_compatibility => v8` unless explicitly configured otherwise.
[2025-03-30T06:16:52,276][INFO ][logstash.javapipeline    ][main] Starting pipeline {:pipeline_id=>"main", "pipeline.workers"=>16, "pipeline.batch.size"=>125, "pipeline.batch.delay"=>50, "pipeline.max_inflight"=>2000, "pipeline.sources"=>["/usr/share/logstash/pipeline/filter.conf", "/usr/share/logstash/pipeline/input.conf", "/usr/share/logstash/pipeline/output.conf"], :thread=>"#<Thread:0x3e72d208 /usr/share/logstash/logstash-core/lib/logstash/java_pipeline.rb:138 run>"}
[2025-03-30T06:16:52,285][INFO ][logstash.javapipeline    ][main] Pipeline Java execution initialization time {"seconds"=>0.01}
[2025-03-30T06:16:52,289][INFO ][logstash.inputs.file     ][main] No sincedb_path set, generating one based on the "path" setting {:sincedb_path=>"/usr/share/logstash/data/plugins/inputs/file/.sincedb_626ad8c2999fb951c5cb28879eb0ea54", :path=>["/tmp/log.txt"]}
[2025-03-30T06:16:52,290][INFO ][logstash.javapipeline    ][main] Pipeline started {"pipeline.id"=>"main"}
[2025-03-30T06:16:52,291][INFO ][filewatch.observingtail  ][main][349f3e814e2fe4b93d583f918d6bcb6bf7908ef2859a1ba828eed83239b3d536] START, creating Discoverer, Watch with file and sincedb collections
[2025-03-30T06:16:52,297][INFO ][logstash.agent           ] Pipelines running {:count=>1, :running_pipelines=>[:main], :non_running_pipelines=>[]}
{
    "@timestamp" => 2025-03-30T06:16:52.299081408Z,
       "message" => "hello",
           "log" => {
        "file" => {
            "path" => "/tmp/log.txt"
        }
    },
      "@version" => "1",
         "event" => {
        "original" => "hello"
    },
          "host" => {
        "name" => "d0b9c30af87b"
    }
}

結果

  • 目視のため個別記載省略

資材

https://github.com/necoskijanen/logstash-reload-test/tree/main

Discussion