KibanaのSearch Profilerで見れるnext_docって何者？

目的

ここ最近KibanaのSearch Profilerを実行することがあったが，結果にあるnext_docが何なのかを知りたくなったので調べてみる．

next_docとは

next_docはLuceneのメソッドの一つであり，検索クエリにマッチする次のドキュメントのDoc IDを返します．つまりnext_docで計測した数値は次にマッチするドキュメントを決めるのに要する時間を計測することができます．

next_docの動作は，諸々調べた結果以下のようなイメージです．(間違っていたらすいません)

Luceneインデックス内にドキュメントがあり，緑のドキュメントがマッチするドキュメントだとします．図だとDoc1にマッチすると次はDoc3ですが，この次のDoc3が見つかるまでの時間をSearch Profilerのnext_docは計測し，ドキュメントのマッチが終わるまで計測し続けます．
最終的に計測した時間を平均にしてKibanaのUIに返されています(おそらく他の数値も考慮されている気がするがそこまで調べられていない)

コードを調べてみる

実際にLuceneのコードを見てみます．
見る対象はDocIdSetIteratorという抽象クラスのallメソッドです．このallメソッドはテスト用のコードとは思われます．ref: code

DocIdSetIterator.java

public abstract class DocIdSetIterator {
  ...
  public static final DocIdSetIterator all(int maxDoc) {
    return new DocIdSetIterator() {
      int doc = -1;


      @Override
      public int docID() {
        return doc;
      }


      @Override
      public int nextDoc() throws IOException {
        return advance(doc + 1);
      }


      @Override
      public int advance(int target) throws IOException {
        doc = target;
        if (doc >= maxDoc) {
          doc = NO_MORE_DOCS;
        }
        return doc;
      }


      @Override
      public long cost() {
        return maxDoc;
      }
    };
  }

allの引数はmaxDocと最大ドキュメント数を引数にしています．
nextDocはadvance(doc + 1);を返しており，これは現在のdoc idの次のドキュメントIDをマッチしようとしています．advanceは，docがmaxDocに到達していなかったら次のdocを返しています．
ここでは計測はしていませんが，実際の計測の例としてQueryProfilerScorerクラスを見てみます．ref: code

QueryProfilerScorer.java

class QueryProfilerScorer extends Scorer {
  private final Scorer scorer;
  private final QueryProfilerTimer scoreTimer,
      nextDocTimer,
      advanceTimer,
      matchTimer,
      shallowAdvanceTimer,
      computeMaxScoreTimer,
      setMinCompetitiveScoreTimer;

  QueryProfilerScorer(Scorer scorer, QueryProfilerBreakdown profile) {
    this.scorer = scorer;
    scoreTimer = profile.getTimer(QueryProfilerTimingType.SCORE);
    nextDocTimer = profile.getTimer(QueryProfilerTimingType.NEXT_DOC);
    advanceTimer = profile.getTimer(QueryProfilerTimingType.ADVANCE);
    matchTimer = profile.getTimer(QueryProfilerTimingType.MATCH);
    shallowAdvanceTimer = profile.getTimer(QueryProfilerTimingType.SHALLOW_ADVANCE);
    computeMaxScoreTimer = profile.getTimer(QueryProfilerTimingType.COMPUTE_MAX_SCORE);
    setMinCompetitiveScoreTimer =
        profile.getTimer(QueryProfilerTimingType.SET_MIN_COMPETITIVE_SCORE);
  }
...
  @Override
  public DocIdSetIterator iterator() {
    final DocIdSetIterator in = scorer.iterator();
    return new DocIdSetIterator() {

      @Override
      public int advance(int target) throws IOException {
        advanceTimer.start();
        try {
          return in.advance(target);
        } finally {
          advanceTimer.stop();
        }
      }

      @Override
      public int nextDoc() throws IOException {
        nextDocTimer.start();
        try {
          return in.nextDoc();
        } finally {
          nextDocTimer.stop();
        }
      }

      @Override
      public int docID() {
        return in.docID();
      }

      @Override
      public long cost() {
        return in.cost();
      }
    };
  }

nextDocメソッドを見るとnextdocTimer.start()で計測を返し，finallyブロックで計測が停止するようになっています．
クエリによって計測方法に違いはあると思いますが、基本的にSearch Profilerのnext_docはこのように計測されているのだと思います．

まとめ

今回初めてガッツリとElasticsearchやLuceneのコードリーディングを行いましたが，非常に勉強になりました．今回はElasticsearchのコードリーディングの結果を載せられなかったのが心残りです...
ただ引き続き，コードリーディングをして記事にしていきたいと思います．

参考文献