Add ability to profile query and collectors

Provides a new flag which can be enabled on a per-request basis.
When `"profile": true` is set, the search request will execute in a
mode that collects detailed timing information for query components.

```
GET /test/test/_search
{
   "profile": true,
   "query": {
      "match": {
         "foo": "bar"
      }
   }
}
```

Closes #14889

Squashed commit of the following:

commit a92db5723d2c61b8449bd163d2f006d12f9889ad
Merge: 117dd99 3f87b08
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Thu Dec 17 09:44:10 2015 -0500

    Merge remote-tracking branch 'upstream/master' into query_profiler

commit 117dd9992e8014b70203c6110925643769d80e62
Merge: 9b29d68 82a64fd
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Dec 15 13:27:18 2015 -0500

    Merge remote-tracking branch 'upstream/master' into query_profiler

    Conflicts:
    	core/src/main/java/org/elasticsearch/search/SearchService.java

commit 9b29d6823a71140ecd872df25ff9f7478e7fe766
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Dec 14 16:13:23 2015 -0500

    [TEST] Profile flag needs to be set, ensure searches go against primary only for consistency

commit 4d602d8ad1f8cbc7b475450921fa3bc7d395b34f
Merge: 8b48e87 7742c1e
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Dec 14 10:56:25 2015 -0500

    Merge remote-tracking branch 'upstream/master' into query_profiler

commit 8b48e876348b163ab730eeca7fa35142165b05f9
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Dec 14 10:56:01 2015 -0500

    Delegate straight to in.matchCost, no need for profiling

commit fde3b0587911f0b5f15e779c671d0510cbd568a9
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Dec 14 10:28:23 2015 -0500

    Documentation tweaks, renaming build_weight -> create_weight

commit 46f5e011ee23fe9bb8a1f11ceb4fa9d19fe48e2e
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Dec 14 10:27:52 2015 -0500

    Profile TwoPhaseIterator should override matchCost()

commit b59f894ddb11b2a7beebba06c4ec5583ff91a7b2
Merge: 9aa1a3a b4e0c87
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Dec 9 14:23:26 2015 -0500

    Merge remote-tracking branch 'upstream/master' into query_profiler

commit 9aa1a3a25c34c9cd9fffaa6114c25a0ec791307d
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Dec 9 13:41:48 2015 -0500

    Revert "Move some of the collector wrapping logic into ProfileCollectorBuilder"

    This reverts commit 02cc31767fb76a7ecd44a302435e93a05fb4220e.

commit 57f7c04cea66b3f98ba2bec4879b98e4fba0b3c0
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Dec 9 13:41:31 2015 -0500

    Revert "Rearrange if/else to make intent clearer"

    This reverts commit 59b63c533fcaddcdfe4656e86a6f6c4cb1bc4a00.

commit 2874791b9c9cd807113e75e38be465f3785c154e
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Dec 9 13:38:13 2015 -0500

    Revert "Move state into ProfileCollectorBuilder"

    This reverts commit 0bb3ee0dd96170b06f07ec9e2435423d686a5ae6.

commit 0bb3ee0dd96170b06f07ec9e2435423d686a5ae6
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Thu Dec 3 11:21:55 2015 -0500

    Move state into ProfileCollectorBuilder

commit 59b63c533fcaddcdfe4656e86a6f6c4cb1bc4a00
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Dec 2 17:21:12 2015 -0500

    Rearrange if/else to make intent clearer

commit 511db0af2f3a86328028b88a6b25fa3dfbab963b
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Dec 2 17:12:06 2015 -0500

    Rename WEIGHT -> BUILD_WEIGHT

commit 02cc31767fb76a7ecd44a302435e93a05fb4220e
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Dec 2 17:11:22 2015 -0500

    Move some of the collector wrapping logic into ProfileCollectorBuilder

commit e69356d3cb4c60fa281dad36d84faa64f5c32bc4
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Nov 30 15:12:35 2015 -0500

    Cleanup imports

commit c1b4f284f16712be60cd881f7e4a3e8175667d62
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Nov 30 15:11:25 2015 -0500

    Review cleanup: Make InternalProfileShardResults writeable

commit 9e61c72f7e1787540f511777050a572b7d297636
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Nov 30 15:01:22 2015 -0500

    Review cleanup: Merge ProfileShardResult, InternalProfileShardResult.  Convert to writeable

commit 709184e1554f567c645690250131afe8568a5799
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Nov 30 14:38:08 2015 -0500

    Review cleanup: Merge ProfileResult, InternalProfileResult.  Convert to writeable

commit 7d72690c44f626c34e9c608754bc7843dd7fd8fe
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Nov 30 14:01:34 2015 -0500

    Review cleanup: use primitive (and default) for profile flag

commit 97d557388541bbd3388cdcce7d9718914d88de6d
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Nov 30 13:09:12 2015 -0500

    Review cleanup: Use Collections.emptyMap() instead of building an empty one explicitly

commit 219585b8729a8b0982e653d99eb959efd0bef84e
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Nov 30 13:08:12 2015 -0500

    Add todo to revisit profiler architecture in the future

commit b712edb2160e032ee4b2f2630fadf131a0936886
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Nov 30 13:05:32 2015 -0500

    Split collector serialization from timing, use writeable instead of streamable

    Previously, the collector timing was done in the same class that was serialized, which required
    leaving the collector null when serializing.  Besides being a bit gross, this made it difficult to
    change the class to Writeable.

    This splits up the timing (InternalProfileCollector + ProfileCollector) and the serialization of
    the times (CollectorResult).  CollectorResult is writeable, and also acts as the public interface.

commit 6ddd77d066262d4400e3d338b11cebe7dd27ca78
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Nov 25 13:15:12 2015 -0500

    Remove dead code

commit 06033f8a056e2121d157654a65895c82bbe93a51
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Nov 25 12:49:51 2015 -0500

    Review cleanup:  Delegate to in.getProfilers()

    Note:  Need to investigate how this is used exactly so we can add a test, it isn't touched by a
    normal inner_hits query...

commit a77e13da21b4bad1176ca2b5d5b76034fb12802f
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Nov 25 11:59:58 2015 -0500

    Review cleanup:  collapse to single `if` statement

commit e97bb6215a5ebb508b0293ac3acd60d5ae479be1
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Nov 25 11:39:43 2015 -0500

    Review cleanup: Return empty map instead of null for profile results

    Note: we still need to check for nullness in SearchPhaseController, since an empty/no-hits result
    won't have profiling instantiated (or any other component like aggs or suggest).  Therefore
    QuerySearchResult.profileResults() is still @Nullable

commit db8e691de2a727389378b459fa76c942572e6015
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Nov 25 10:14:47 2015 -0500

    Review cleanup: renaming, formatting fixes, assertions

commit 9011775fe80ba22c2fd948ca64df634b4e32772d
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Thu Nov 19 20:09:52 2015 -0500

    [DOCS] Add missing annotation

commit 4b58560b06f08d4b99b149af20916ee839baabd7
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Thu Nov 19 20:07:17 2015 -0500

    [DOCS] Update documentation for new format

commit f0458c58e5538ed8ec94849d4baf3250aa9ec841
Author: Adrien Grand <jpountz@gmail.com>
Date:   Tue Nov 17 10:14:09 2015 +0100

    Reduce visibility of internal classes.

commit d0a7d319098e60b028fa772bf8a99b2df9cf6146
Merge: e158070 1bdf29e
Author: Adrien Grand <jpountz@gmail.com>
Date:   Tue Nov 17 10:09:18 2015 +0100

    Merge branch 'master' into query_profiler

commit e158070a48cb096551f3bb3ecdcf2b53bbc5e3c5
Author: Adrien Grand <jpountz@gmail.com>
Date:   Tue Nov 17 10:08:48 2015 +0100

    Fix compile error due to bad html in javadocs.

commit a566b5d08d659daccb087a9afbe908ec3d96cd6e
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Nov 16 17:48:37 2015 -0500

    Remove unused collector

commit 4060cd72d150cc68573dbde62ca7321c47f75703
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Nov 16 17:48:10 2015 -0500

    Comment cleanup

commit 43137952bf74728f5f5d5a8d1bfc073e0f9fe4f9
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Nov 16 17:32:06 2015 -0500

    Fix negative formatted time

commit 5ef3a980266326aff12d4fe380f73455ff28209f
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Nov 13 17:10:17 2015 +0100

    Fix javadocs.

commit 276114d29e4b17a0cc0982cfff51434f712dc59e
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Nov 13 16:25:23 2015 +0100

    Fix: include rewrite time as well...

commit 21d9e17d05487bf4903ae3d2ab6f429bece2ffef
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Nov 13 15:10:15 2015 +0100

    Remove TODO about profiling explain.

commit 105a31e8e570efb879447159c3852871f5cf7db4
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Nov 13 14:59:30 2015 +0100

    Fix nocommit now that the global collector is a root collector.

commit 2e8fc5cf84adb1bfaba296808c329e5f982c9635
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Nov 13 14:53:38 2015 +0100

    Make collector wrapping more explicit/robust (and a bit less magical).

commit 5e30b570b0835e1ce79a57933a31b6a2d0d58e2d
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Nov 13 12:44:03 2015 +0100

    Simplify recording API a bit.

commit 9b453afced6adc0a59ca1d67d90c28796b105185
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Nov 13 10:54:25 2015 +0100

    Fix serialization-related nocommits.

commit ad97b200bb123d4e9255e7c8e02f7e43804057a5
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Nov 13 10:46:30 2015 +0100

    Fix DFS.

commit a6de06986cd348a831bd45e4f524d2e14d9e03c3
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Nov 12 19:29:16 2015 +0100

    Remove forbidden @Test annotation.

commit 4991a28e19501109af98026e14756cb25a56f4f4
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Nov 12 19:25:59 2015 +0100

    Limit the impact of query profiling on the SearchContext API.

    Rule is: we can put as much as we want in the search.profile package but should
    aim at touching as little as possible other areas of the code base.

commit 353d8d75a5ce04d9c3908a0a63d4ca6e884c519a
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Nov 12 18:05:09 2015 +0100

    Remove dead code.

commit a3ffafb5ddbb5a2acf43403c946e5ed128f47528
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Nov 12 15:30:35 2015 +0100

    Remove call to forbidden String.toLowerCase() API.

commit 1fa8c7a00324fa4e32bd24135ebba5ecf07606f1
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Nov 12 15:30:27 2015 +0100

    Fix compilation.

commit 2067f1797e53bef0e1a8c9268956bc5fb8f8ad97
Merge: 22e631f fac472f
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Nov 12 15:21:12 2015 +0100

    Merge branch 'master' into query_profiler

commit 22e631fe6471fed19236578e97c628d5cda401a9
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Nov 3 18:52:05 2015 -0500

    Fix and simplify serialization of shard profile results

commit 461da250809451cd2b47daf647343afbb4b327f2
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Nov 3 18:32:22 2015 -0500

    Remove helper methods, simpler without them

commit 5687aa1c93d45416d895c2eecc0e6a6b302139f2
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Nov 3 18:29:32 2015 -0500

    [TESTS] Fix tests for new rewrite format

commit ba9e82857fc6d4c7b72ef4d962d2102459365299
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Fri Oct 30 15:28:14 2015 -0400

    Rewrites begone! Record all rewrites as a single time metric

commit 5f28d7cdff9ee736651d564f71f713bf45fb1d91
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Thu Oct 29 15:36:06 2015 -0400

    Merge duplicate rewrites into one entry

    By using the Query as the key in a map, we can easily merge rewrites together.  This means
    the preProcess(), assertion and main query rewrites all get merged together.  Downside is that
    rewrites of the same Query (hashcode) but in different places get lumped together.  I think the
    simplicity of the solution is better than the slight loss in output fidelity.

commit 9a601ea46bb21052746157a45dcc6de6bc350e9c
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Thu Oct 29 15:28:27 2015 -0400

    Allow multiple "searches" per profile (e.g. query + global agg)

commit ee30217328381cd83f9e653d3a4d870c1d2bdfce
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Thu Oct 29 11:29:18 2015 -0400

    Update comment, add nullable annotation

commit 405c6463a64e118f170959827931e8c6a1661f13
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Thu Oct 29 11:04:30 2015 -0400

    remove out-dated comment

commit 2819ae8f4cf1bfd5670dbd1c0e06195ae457b58f
Author: Adrien Grand <jpountz@gmail.com>
Date:   Tue Oct 27 19:50:47 2015 +0100

    Don't render children in the profiles when there are no children.

commit 7677c2ddefef321bbe74660471603d202a4ab66f
Author: Adrien Grand <jpountz@gmail.com>
Date:   Tue Oct 27 19:50:35 2015 +0100

    Set the profiler on the ContextIndexSearcher.

commit 74a4338c35dfed779adc025ec17cfd4d1c9f66f5
Author: Adrien Grand <jpountz@gmail.com>
Date:   Tue Oct 27 19:50:01 2015 +0100

    Fix json rendering.

commit 6674d5bebe187b0b0d8b424797606fdf2617dd27
Author: Adrien Grand <jpountz@gmail.com>
Date:   Tue Oct 27 19:20:19 2015 +0100

    Revert "nocommit - profiling never enabled because setProfile() on ContextIndexSearcher never called"

    This reverts commit d3dc10949024342055f0d4fb7e16c7a43423bfab.

commit d3dc10949024342055f0d4fb7e16c7a43423bfab
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Fri Oct 23 17:20:57 2015 -0400

    nocommit - profiling never enabled because setProfile() on ContextIndexSearcher never called

    Previously, it was enabled by using DefaultSearchContext as a third-party "proxy", but since
    the refactor to make it unit testable, setProfile() needs to be called explicitly.  Unfortunately,
    this is not possible because SearchService only has access to an IndexSearcher.  And it is not
    cast'able to a DefaultIndexSearcher.

commit b9ba9c5d1f93b9c45e97b0a4e35da6f472c9ea53
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Fri Oct 23 16:27:00 2015 -0400

    [TESTS] Fix unit tests

commit cf5d1e016b2b4a583175e07c16c7152f167695ce
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Fri Oct 23 16:22:34 2015 -0400

    Increment token after recording a rewrite

commit b7d08f64034e498533c4a81bff8727dd8ac2843e
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Fri Oct 23 16:14:09 2015 -0400

    Fix NPE if a top-level root doesn't have children

commit e4d3b514bafe2a3a9db08438c89f0ed68628f2d6
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Fri Oct 23 16:05:47 2015 -0400

    Fix NPE when profiling is disabled

commit 445384fe48ed62fdd01f7fc9bf3e8361796d9593
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Fri Oct 23 16:05:37 2015 -0400

    [TESTS] Fix integration tests

commit b478296bb04fece827a169e7522df0a5ea7840a3
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Fri Oct 23 15:43:24 2015 -0400

    Move rewrites to their own section, remove reconciliation

    Big commit because the structural change affected a lot of the wrapping code.  Major changes:

    - Rewrites are now in their own section in the response
    - Reconciliation is gone...we don't attempt to roll the rewrites into the query tree structure
    - InternalProfileShardResults (plural) simply holds a Map<String, InternalProfileShardResult> and
    helps to serialize / ToXContent
    - InternalProfileShardResult (singular) is now the holder for all shard-level profiling details. Currently
    this includes query, collectors and rewrite.  In the future it would hold suggest, aggs, etc
    - When the user requests the profiled results, they get back a Map<String, ProfileShardResult>
    instead of doing silly helper methods to convert to maps, etc
    - Shard details are baked into a string instead of serializing the object

commit 24819ad094b208d0e94f17ce9c3f7c92f7414124
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Fri Oct 23 10:25:38 2015 -0400

    Make Profile results immutable by removing relative_time

commit bfaf095f45fed74194ef78160a8e5dcae1850f9e
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Oct 23 10:54:59 2015 +0200

    Add nocommits.

commit e9a128d0d26d5b383b52135ca886f2c987850179
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Oct 23 10:39:37 2015 +0200

    Move all profile-related classes to the same package.

commit f20b7c7fdf85384ecc37701bb65310fb8c20844f
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Oct 23 10:33:14 2015 +0200

    Reorganize code a bit to ease unit testing of ProfileCollector.

commit 3261306edad6a0c70f59eaee8fe58560f61a75fd
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Oct 22 18:07:28 2015 +0200

    Remove irrelevant nocommit.

commit a6ac868dad12a2e17929878681f66dbd0948d322
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Oct 22 18:06:45 2015 +0200

    Make CollectorResult's reason a free-text field to ease bw compat.

commit 5d0bf170781a950d08b81871cd1e403e49f3cc12
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Oct 22 16:50:52 2015 +0200

    Add unit tests for ProfileWeight/ProfileScorer.

commit 2cd88c412c6e62252504ef69a59216adbb574ce4
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Oct 22 15:55:17 2015 +0200

    Rename InternalQueryProfiler to Profiler.

commit 84f5718fa6779f710da129d9e0e6ff914fd85e36
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Oct 22 15:53:58 2015 +0200

    Merge InternalProfileBreakdown into ProfileBreakdown.

commit 135168eaeb8999c8117ea25288104b0961ce9b35
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Oct 22 13:56:57 2015 +0200

    Make it possible to instantiate a ContextIndexSearcher without SearchContext.

commit 5493fb52376b48460c4ce2dedbe00cc5f6620499
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Oct 22 11:53:29 2015 +0200

    Move ProfileWeight/Scorer to their own files.

commit bf2d917b9dae3b32dfc29c35a7cac4ccb7556cce
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Oct 22 11:38:24 2015 +0200

    Fix bug that caused phrase queries to fail.

commit b2bb0c92c343334ec1703a221af24a1b55e36d53
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Oct 22 11:36:17 2015 +0200

    Parsing happens on the coordinating node now.

commit 416cabb8621acb5cd8dfa77374fd23e428f52fe9
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Oct 22 11:22:17 2015 +0200

    Fix compilation (in particular remove guava deps).

commit f996508645f842629d403fc2e71c1890c0e2cac9
Merge: 4616a25 bc3b91e
Author: Adrien Grand <jpountz@gmail.com>
Date:   Thu Oct 22 10:44:38 2015 +0200

    Merge branch 'master' into query_profiler

commit 4616a25afffe9c24c6531028f7fccca4303d2893
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Oct 20 12:11:32 2015 -0400

    Make Java Count API compatible with profiling

commit cbfba74e16083d719722500ac226efdb5cb2ff55
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Oct 20 12:11:19 2015 -0400

    Fix serialization of profile query param, NPE

commit e33ffac383b03247046913da78c8a27e457fae78
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Oct 20 11:17:48 2015 -0400

    TestSearchContext should return null Profiler instead of exception

commit 73a02d69b466dc1a5b8a5f022464d6c99e6c2ac3
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Oct 19 12:07:29 2015 -0400

    [DOCS] Update docs to reflect new ID format

commit 36248e388c354f954349ecd498db7b66f84ce813
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Oct 19 12:03:03 2015 -0400

    Use the full [node][index][shard] string as profile result ID

commit 5cfcc4a6a6b0bcd6ebaa7c8a2d0acc32529a80e1
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Thu Oct 15 17:51:40 2015 -0400

    Add failing test for phrase matching

    Stack trace generated:

    [2015-10-15 17:50:54,438][ERROR][org.elasticsearch.search.profile] shard [[JNj7RX_oSJikcnX72aGBoA][test][2]], reason [RemoteTransportException[[node_s0][local[1]][indices:data/read/search[phase/query]]]; nested: QueryPhaseExecutionException[Query Failed [Failed to execute main query]]; nested: AssertionError[nextPosition() called more than freq() times!]; ], cause [java.lang.AssertionError: nextPosition() called more than freq() times!
    	at org.apache.lucene.index.AssertingLeafReader$AssertingPostingsEnum.nextPosition(AssertingLeafReader.java:353)
    	at org.apache.lucene.search.ExactPhraseScorer.phraseFreq(ExactPhraseScorer.java:132)
    	at org.apache.lucene.search.ExactPhraseScorer.access$000(ExactPhraseScorer.java:27)
    	at org.apache.lucene.search.ExactPhraseScorer$1.matches(ExactPhraseScorer.java:69)
    	at org.elasticsearch.common.lucene.search.ProfileQuery$ProfileScorer$2.matches(ProfileQuery.java:226)
    	at org.apache.lucene.search.ConjunctionDISI$TwoPhaseConjunctionDISI.matches(ConjunctionDISI.java:175)
    	at org.apache.lucene.search.ConjunctionDISI$TwoPhase.matches(ConjunctionDISI.java:213)
    	at org.apache.lucene.search.ConjunctionDISI.doNext(ConjunctionDISI.java:128)
    	at org.apache.lucene.search.ConjunctionDISI.nextDoc(ConjunctionDISI.java:151)
    	at org.apache.lucene.search.ConjunctionScorer.nextDoc(ConjunctionScorer.java:62)
    	at org.elasticsearch.common.lucene.search.ProfileQuery$ProfileScorer$1.nextDoc(ProfileQuery.java:205)
    	at org.apache.lucene.search.Weight$DefaultBulkScorer.scoreAll(Weight.java:224)
    	at org.apache.lucene.search.Weight$DefaultBulkScorer.score(Weight.java:169)
    	at org.apache.lucene.search.BulkScorer.score(BulkScorer.java:39)
    	at org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:795)
    	at org.apache.lucene.search.IndexSearcher.search(IndexSearcher.java:509)
    	at org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:347)
    	at org.elasticsearch.search.query.QueryPhase.execute(QueryPhase.java:111)
    	at org.elasticsearch.search.SearchService.loadOrExecuteQueryPhase(SearchService.java:366)
    	at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:378)
    	at org.elasticsearch.search.action.SearchServiceTransportAction$SearchQueryTransportHandler.messageReceived(SearchServiceTransportAction.java:368)
    	at org.elasticsearch.search.action.SearchServiceTransportAction$SearchQueryTransportHandler.messageReceived(SearchServiceTransportAction.java:365)
    	at org.elasticsearch.transport.local.LocalTransport$2.doRun(LocalTransport.java:280)
    	at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37)
    	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    	at java.lang.Thread.run(Thread.java:745)

commit 889fe6383370fe919aaa9f0af398e3040209e40b
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Thu Oct 15 17:30:38 2015 -0400

    [DOCS] More docs

commit 89177965d031d84937753538b88ea5ebae2956b0
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Thu Oct 15 09:59:09 2015 -0400

    Fix multi-stage rewrites to recursively find most appropriate descendant rewrite

    Previously, we chose the first rewrite that matched.  But in situations where a query may
    rewrite several times, this won't build the tree correctly.  Instead we need to recurse
    down all the rewrites until we find the most appropriate "leaf" rewrite

    The implementation of this is kinda gross: we recursively call getRewrittenParentToken(),
    which does a linear scan over the rewriteMap and tries to find rewrites with a larger token
    value (since we know child tokens are always larger).  Can almost certainly find a better
    way to do this...

commit 0b4d782b5348e5d03fd26f7d91bc4a3fbcb7f6a5
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Oct 14 19:30:06 2015 -0400

    [Docs] Documentation checkpoint

commit 383636453f6610fcfef9070c21ae7ca11346793e
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Sep 16 16:02:22 2015 -0400

    Comments

commit a81e8f31e681be16e89ceab9ba3c3e0a018f18ef
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Sep 16 15:48:49 2015 -0400

    [TESTS] Ensure all tests use QUERY_THEN_FETCH, DFS does not profile

commit 1255c2d790d85fcb9cbb78bf2a53195138c6bc24
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Sep 15 16:43:46 2015 -0400

    Refactor rewrite handling to handle identical rewrites

commit 85b7ec82eb0b26a6fe87266b38f5f86f9ac0c44f
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Sep 15 08:51:14 2015 -0400

    Don't update parent when a token is added as root -- Fixes NPE

commit 109d02bdbc49741a3b61e8624521669b0968b839
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Sep 15 08:50:40 2015 -0400

    Don't set the rewritten query if not profiling -- Fixes NPE

commit 233cf5e85f6f2c39ed0a2a33d7edd3bbd40856e8
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Sep 14 18:04:51 2015 -0400

    Update tests to new response format

commit a930b1fc19de3a329abc8ffddc6711c1246a4b15
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Sep 14 18:03:58 2015 -0400

    Fix serialization

commit 69afdd303660510c597df9bada5531b19d134f3d
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Sep 14 15:11:31 2015 -0400

    Comments and cleanup

commit 64e7ca7f78187875378382ec5d5aa2462ff71df5
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Sep 14 14:40:21 2015 -0400

    Move timing into dedicated class, add proper rewrite integration

commit b44ff85ddbba0a080e65f2e7cc8c50d30e95df8e
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Sep 14 12:00:38 2015 -0400

    Checkpoint - Refactoring to use a token-based dependency tree

commit 52cedd5266d6a87445c6a4cff3be8ff2087cd1b7
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Fri Sep 4 19:18:19 2015 -0400

    Need to set context profiling flag before calling queryPhase.preProcess

commit c524670cb1ce29b4b3a531fa2bff0c403b756f46
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Sep 4 18:00:37 2015 +0200

    Reduce profiling overhead a bit.

    This removes hash-table lookups everytime we start/stop a profiling clock.

commit 111444ff8418737082236492b37321fc96041e09
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Sep 4 16:18:59 2015 +0200

    Add profiling of two-phase iterators.

    This is useful for eg. phrase queries or script filters, since they are
    typically consumed through their two-phase iterator instead of the scorer.

commit f275e690459e73211bc8494c6de595c0320f4c0b
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Sep 4 16:03:21 2015 +0200

    Some more improvements.

    I changed profiling to disable bulk scoring, since it makes it impossible to
    know where time is spent. Also I removed profiling of operations that are
    always fast (eg. normalization) and added nextDoc/advance.

commit 3c8dcd872744de8fd76ce13b6f18f36f8de44068
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Sep 4 14:39:50 2015 +0200

    Remove println.

commit d68304862fb38a3823aebed35a263bd9e2176c2f
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Sep 4 14:36:03 2015 +0200

    Fix some test failures introduced by the rebase...

commit 04d53ca89fb34b7a21515d770c32aaffcc513b90
Author: Adrien Grand <jpountz@gmail.com>
Date:   Fri Sep 4 13:57:35 2015 +0200

    Reconcile conflicting changes after rebase

commit fed03ec8e2989a0678685cd6c50a566cec42ea4f
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Thu Aug 20 22:40:39 2015 -0400

    Add Collectors to profile results

    Profile response element has now been re-arranged so that everything is listed per-shard to
    facilitate grouping elements together.  The new `collector` element looks like this:

    ```
    "profile": {
      "shards": [
         {
            "shard_id": "keP4YFywSXWALCl4m4k24Q",
            "query": [...],
            "collector": [
               {
                  "name": "MultiCollector",
                  "purpose": "search_multi",
                  "time": "16.44504400ms",
                  "relative_time": "100.0000000%",
                  "children": [
                     {
                        "name": "FilteredCollector",
                        "purpose": "search_post_filter",
                        "time": "4.556013000ms",
                        "relative_time": "27.70447437%",
                        "children": [
                           {
                              "name": "SimpleTopScoreDocCollector",
                              "purpose": "search_sorted",
                              "time": "1.352166000ms",
                              "relative_time": "8.222331299%",
                              "children": []
                           }
                        ]
                     },
                     {
                        "name": "BucketCollector: [[non_global_term, another_agg]]",
                        "purpose": "aggregation",
                        "time": "10.40379400ms",
                        "relative_time": "63.26400829%",
                        "children": []
                     },
           ...
    ```

commit 1368b495c934be642c00f6cbf9fc875d7e6c07ff
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Aug 19 12:43:03 2015 -0400

    Move InternalProfiler to profile package

commit 53584de910db6d4a6bb374c9ebb954f204882996
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Aug 18 18:34:58 2015 -0400

    Only reconcile rewrite timing when rewritten query is different from original

commit 9804c3b29d2107cd97f1c7e34d77171b62cb33d0
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Aug 18 16:40:15 2015 -0400

    Comments and cleanup

commit 8e898cc7c59c0c1cc5ed576dfed8e3034ca0967f
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Aug 18 14:19:07 2015 -0400

    [TESTS] Fix comparison test to ensure results sort identically

commit f402a29001933eef29d5a62e81c8563f1c8d0969
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Aug 18 14:17:59 2015 -0400

    Add note about DFS being unable to profile

commit d446e08d3bc91cd85b24fc908e2d82fc5739d598
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Aug 18 14:17:23 2015 -0400

    Implement some missing methods

commit 13ca94fb86fb037a30d181b73d9296153a63d6e4
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Aug 18 13:10:54 2015 -0400

    [TESTS] Comments & cleanup

commit c76c8c771fdeee807761c25938a642612a6ed8e7
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Aug 18 13:06:08 2015 -0400

    [TESTS] Fix profileMatchesRegular to handle NaN scores and nearlyEqual floats

commit 7e7a10ecd26677b2239149468e24938ce5cc18e1
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Aug 18 12:22:16 2015 -0400

    Move nearlyEquals() utility function to shared location

commit 842222900095df4b27ff3593dbb55a42549f2697
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Aug 18 12:04:35 2015 -0400

    Fixup rebase conflicts

commit 674f162d7704dd2034b8361358decdefce1f76ce
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Aug 17 15:29:35 2015 -0400

    [TESTS] Update match and bool tests

commit 520380a85456d7137734aed0b06a740e18c9cdec
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Aug 17 15:28:09 2015 -0400

    Make naming consistent re: plural

commit b9221501d839bb24d6db575d08e9bee34043fc65
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Aug 17 15:27:39 2015 -0400

    Children need to be added to list after serialization

commit 05fa51df940c332fbc140517ee56e849f2d40a72
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Aug 17 15:22:41 2015 -0400

    Re-enable bypass for non-profiled queries

commit f132204d264af77a75bd26a02d4e251a19eb411d
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Aug 17 15:21:14 2015 -0400

    Fix serialization of QuerySearchResult, InternalProfileResult

commit 27b98fd475fc2e9508c91436ef30624bdbee54ba
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Aug 10 17:39:17 2015 -0400

    Start to add back tests, refactor Java api

commit bcfc9fefd49307045108408dc160774666510e85
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Aug 4 17:08:10 2015 -0400

    Checkpoint

commit 26a530e0101ce252450eb23e746e48c2fd1bfcae
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Tue Jul 14 13:30:32 2015 -0400

    Add createWeight() checkpoint

commit f0dd61de809c5c13682aa213c0be65972537a0df
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Mon Jul 13 12:36:27 2015 -0400

    checkpoint

commit 377ee8ce5729b8d388c4719913b48fae77a16686
Author: Zachary Tong <zacharyjtong@gmail.com>
Date:   Wed Mar 18 10:45:01 2015 -0400

    checkpoint
This commit is contained in:
Zachary Tong 2015-12-17 12:05:43 -05:00
parent c31117f1e8
commit 9a70dbb51a
38 changed files with 3599 additions and 35 deletions

View File

@ -473,6 +473,14 @@ public class SearchRequestBuilder extends ActionRequestBuilder<SearchRequest, Se
return this;
}
/**
* Should the query be profiled. Defaults to <code>false</code>
*/
public SearchRequestBuilder setProfile(boolean profile) {
sourceBuilder().profile(profile);
return this;
}
@Override
public String toString() {
if (request.source() != null) {

View File

@ -20,6 +20,7 @@
package org.elasticsearch.action.search;
import org.elasticsearch.action.ActionResponse;
import org.elasticsearch.common.Nullable;
import org.elasticsearch.common.io.stream.StreamInput;
import org.elasticsearch.common.io.stream.StreamOutput;
import org.elasticsearch.common.unit.TimeValue;
@ -32,9 +33,12 @@ import org.elasticsearch.rest.action.support.RestActions;
import org.elasticsearch.search.SearchHits;
import org.elasticsearch.search.aggregations.Aggregations;
import org.elasticsearch.search.internal.InternalSearchResponse;
import org.elasticsearch.search.profile.ProfileShardResult;
import org.elasticsearch.search.suggest.Suggest;
import java.io.IOException;
import java.util.List;
import java.util.Map;
import static org.elasticsearch.action.search.ShardSearchFailure.readShardSearchFailure;
import static org.elasticsearch.search.internal.InternalSearchResponse.readInternalSearchResponse;
@ -160,6 +164,16 @@ public class SearchResponse extends ActionResponse implements StatusToXContent {
this.scrollId = scrollId;
}
/**
* If profiling was enabled, this returns an object containing the profile results from
* each shard. If profiling was not enabled, this will return null
*
* @return The profile results or null
*/
public @Nullable Map<String, List<ProfileShardResult>> getProfileResults() {
return internalResponse.profile();
}
static final class Fields {
static final XContentBuilderString _SCROLL_ID = new XContentBuilderString("_scroll_id");
static final XContentBuilderString TOOK = new XContentBuilderString("took");

View File

@ -43,7 +43,6 @@ import org.elasticsearch.common.util.BigArrays;
import org.elasticsearch.index.IndexService;
import org.elasticsearch.index.analysis.AnalysisService;
import org.elasticsearch.index.cache.bitset.BitsetFilterCache;
import org.elasticsearch.index.cache.query.QueryCache;
import org.elasticsearch.index.engine.Engine;
import org.elasticsearch.index.fielddata.IndexFieldDataService;
import org.elasticsearch.index.mapper.MappedFieldType;
@ -74,6 +73,8 @@ import org.elasticsearch.search.internal.SearchContext;
import org.elasticsearch.search.internal.ShardSearchRequest;
import org.elasticsearch.search.lookup.LeafSearchLookup;
import org.elasticsearch.search.lookup.SearchLookup;
import org.elasticsearch.search.profile.Profiler;
import org.elasticsearch.search.profile.Profilers;
import org.elasticsearch.search.query.QuerySearchResult;
import org.elasticsearch.search.rescore.RescoreSearchContext;
import org.elasticsearch.search.suggest.SuggestionSearchContext;
@ -139,7 +140,7 @@ public class PercolateContext extends SearchContext {
this.bigArrays = bigArrays.withCircuitBreaking();
this.querySearchResult = new QuerySearchResult(0, searchShardTarget);
this.engineSearcher = indexShard.acquireSearcher("percolate");
this.searcher = new ContextIndexSearcher(this, engineSearcher);
this.searcher = new ContextIndexSearcher(engineSearcher, indexService.cache().query(), indexShard.getQueryCachingPolicy());
this.scriptService = scriptService;
this.numberOfShards = request.getNumberOfShards();
this.aliasFilter = aliasFilter;
@ -748,5 +749,7 @@ public class PercolateContext extends SearchContext {
}
@Override
public QueryCache getQueryCache() { return indexService.cache().query();}
public Profilers getProfilers() {
throw new UnsupportedOperationException();
}
}

View File

@ -23,6 +23,7 @@ import com.carrotsearch.hppc.ObjectFloatHashMap;
import com.carrotsearch.hppc.ObjectHashSet;
import com.carrotsearch.hppc.ObjectSet;
import com.carrotsearch.hppc.cursors.ObjectCursor;
import org.apache.lucene.index.IndexOptions;
import org.apache.lucene.index.LeafReaderContext;
import org.apache.lucene.index.NumericDocValues;
@ -86,6 +87,7 @@ import org.elasticsearch.search.fetch.script.ScriptFieldsContext.ScriptField;
import org.elasticsearch.search.highlight.HighlightBuilder;
import org.elasticsearch.search.internal.*;
import org.elasticsearch.search.internal.SearchContext.Lifetime;
import org.elasticsearch.search.profile.Profilers;
import org.elasticsearch.search.query.*;
import org.elasticsearch.search.warmer.IndexWarmersMetaData;
import org.elasticsearch.threadpool.ThreadPool;
@ -552,7 +554,7 @@ public class SearchService extends AbstractLifecycleComponent<SearchService> imp
Engine.Searcher engineSearcher = searcher == null ? indexShard.acquireSearcher("search") : searcher;
SearchContext context = new DefaultSearchContext(idGenerator.incrementAndGet(), request, shardTarget, engineSearcher, indexService, indexShard, scriptService, pageCacheRecycler, bigArrays, threadPool.estimatedTimeInMillisCounter(), parseFieldMatcher, defaultSearchTimeout);
DefaultSearchContext context = new DefaultSearchContext(idGenerator.incrementAndGet(), request, shardTarget, engineSearcher, indexService, indexShard, scriptService, pageCacheRecycler, bigArrays, threadPool.estimatedTimeInMillisCounter(), parseFieldMatcher, defaultSearchTimeout);
SearchContext.setCurrent(context);
try {
@ -659,7 +661,7 @@ public class SearchService extends AbstractLifecycleComponent<SearchService> imp
}
}
private void parseSource(SearchContext context, SearchSourceBuilder source) throws SearchContextException {
private void parseSource(DefaultSearchContext context, SearchSourceBuilder source) throws SearchContextException {
// nothing to parse...
if (source == null) {
return;
@ -715,6 +717,9 @@ public class SearchService extends AbstractLifecycleComponent<SearchService> imp
if (source.minScore() != null) {
context.minimumScore(source.minScore());
}
if (source.profile()) {
context.setProfilers(new Profilers(context.searcher()));
}
context.timeoutInMillis(source.timeoutInMillis());
context.terminateAfter(source.terminateAfter());
if (source.aggregations() != null) {

View File

@ -20,6 +20,7 @@ package org.elasticsearch.search.aggregations;
import org.apache.lucene.search.BooleanClause.Occur;
import org.apache.lucene.search.BooleanQuery;
import org.apache.lucene.search.Collector;
import org.apache.lucene.search.Query;
import org.elasticsearch.common.inject.Inject;
import org.elasticsearch.common.lucene.search.Queries;
@ -30,10 +31,13 @@ import org.elasticsearch.search.aggregations.pipeline.PipelineAggregator;
import org.elasticsearch.search.aggregations.pipeline.SiblingPipelineAggregator;
import org.elasticsearch.search.aggregations.support.AggregationContext;
import org.elasticsearch.search.internal.SearchContext;
import org.elasticsearch.search.profile.CollectorResult;
import org.elasticsearch.search.profile.InternalProfileCollector;
import org.elasticsearch.search.query.QueryPhaseExecutionException;
import java.io.IOException;
import java.util.ArrayList;
import java.util.Collections;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
@ -81,8 +85,13 @@ public class AggregationPhase implements SearchPhase {
}
context.aggregations().aggregators(aggregators);
if (!collectors.isEmpty()) {
final BucketCollector collector = BucketCollector.wrap(collectors);
collector.preCollection();
Collector collector = BucketCollector.wrap(collectors);
((BucketCollector)collector).preCollection();
if (context.getProfilers() != null) {
collector = new InternalProfileCollector(collector, CollectorResult.REASON_AGGREGATION,
// TODO: report on child aggs as well
Collections.emptyList());
}
context.queryCollectors().put(AggregationPhase.class, collector);
}
} catch (IOException e) {
@ -116,6 +125,7 @@ public class AggregationPhase implements SearchPhase {
BucketCollector globalsCollector = BucketCollector.wrap(globals);
Query query = Queries.newMatchAllQuery();
Query searchFilter = context.searchFilter(context.types());
if (searchFilter != null) {
BooleanQuery filtered = new BooleanQuery.Builder()
.add(query, Occur.MUST)
@ -124,8 +134,20 @@ public class AggregationPhase implements SearchPhase {
query = filtered;
}
try {
final Collector collector;
if (context.getProfilers() == null) {
collector = globalsCollector;
} else {
InternalProfileCollector profileCollector = new InternalProfileCollector(
globalsCollector, CollectorResult.REASON_AGGREGATION_GLOBAL,
// TODO: report on sub collectors
Collections.emptyList());
collector = profileCollector;
// start a new profile with this collector
context.getProfilers().addProfiler().setCollector(profileCollector);
}
globalsCollector.preCollection();
context.searcher().search(query, globalsCollector);
context.searcher().search(query, collector);
} catch (Exception e) {
throw new QueryPhaseExecutionException(context, "Failed to execute global aggregators", e);
} finally {

View File

@ -25,6 +25,7 @@ import org.apache.lucene.search.Collector;
import java.io.IOException;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.List;
import java.util.stream.StreamSupport;
@ -99,6 +100,11 @@ public abstract class BucketCollector implements Collector {
}
return false;
}
@Override
public String toString() {
return Arrays.toString(collectors);
}
};
}
}

View File

@ -22,6 +22,7 @@ package org.elasticsearch.search.builder;
import com.carrotsearch.hppc.ObjectFloatHashMap;
import com.carrotsearch.hppc.cursors.ObjectCursor;
import org.elasticsearch.Version;
import org.elasticsearch.action.support.ToXContentToBytes;
import org.elasticsearch.common.Nullable;
import org.elasticsearch.common.ParseField;
@ -91,6 +92,7 @@ public final class SearchSourceBuilder extends ToXContentToBytes implements Writ
public static final ParseField RESCORE_FIELD = new ParseField("rescore");
public static final ParseField STATS_FIELD = new ParseField("stats");
public static final ParseField EXT_FIELD = new ParseField("ext");
public static final ParseField PROFILE_FIELD = new ParseField("profile");
private static final SearchSourceBuilder PROTOTYPE = new SearchSourceBuilder();
@ -158,6 +160,9 @@ public final class SearchSourceBuilder extends ToXContentToBytes implements Writ
private BytesReference ext = null;
private boolean profile = false;
/**
* Constructs a new search source builder.
*/
@ -475,6 +480,22 @@ public final class SearchSourceBuilder extends ToXContentToBytes implements Writ
return this;
}
/**
* Should the query be profiled. Defaults to <tt>false</tt>
*/
public SearchSourceBuilder profile(boolean profile) {
this.profile = profile;
return this;
}
/**
* Return whether to profile query execution, or {@code null} if
* unspecified.
*/
public boolean profile() {
return profile;
}
/**
* Gets the bytes representing the rescore builders for this request.
*/
@ -723,6 +744,8 @@ public final class SearchSourceBuilder extends ToXContentToBytes implements Writ
builder.fieldNames = fieldNames;
} else if (context.parseFieldMatcher().match(currentFieldName, SORT_FIELD)) {
builder.sort(parser.text());
} else if (context.parseFieldMatcher().match(currentFieldName, PROFILE_FIELD)) {
builder.profile = parser.booleanValue();
} else {
throw new ParsingException(parser.getTokenLocation(), "Unknown key for a " + token + " in [" + currentFieldName + "].",
parser.getTokenLocation());
@ -931,6 +954,10 @@ public final class SearchSourceBuilder extends ToXContentToBytes implements Writ
builder.field(EXPLAIN_FIELD.getPreferredName(), explain);
}
if (profile) {
builder.field("profile", true);
}
if (fetchSourceContext != null) {
builder.field(_SOURCE_FIELD.getPreferredName(), fetchSourceContext);
}
@ -1212,6 +1239,11 @@ public final class SearchSourceBuilder extends ToXContentToBytes implements Writ
if (in.readBoolean()) {
builder.ext = in.readBytesReference();
}
if (in.getVersion().onOrAfter(Version.V_2_2_0)) {
builder.profile = in.readBoolean();
} else {
builder.profile = false;
}
return builder;
}
@ -1325,13 +1357,16 @@ public final class SearchSourceBuilder extends ToXContentToBytes implements Writ
if (hasExt) {
out.writeBytesReference(ext);
}
if (out.getVersion().onOrAfter(Version.V_2_2_0)) {
out.writeBoolean(profile);
}
}
@Override
public int hashCode() {
return Objects.hash(aggregations, explain, fetchSourceContext, fieldDataFields, fieldNames, from,
highlightBuilder, indexBoost, innerHitsBuilder, minScore, postQueryBuilder, queryBuilder, rescoreBuilders, scriptFields,
size, sorts, stats, suggestBuilder, terminateAfter, timeoutInMillis, trackScores, version);
size, sorts, stats, suggestBuilder, terminateAfter, timeoutInMillis, trackScores, version, profile);
}
@Override
@ -1364,6 +1399,7 @@ public final class SearchSourceBuilder extends ToXContentToBytes implements Writ
&& Objects.equals(terminateAfter, other.terminateAfter)
&& Objects.equals(timeoutInMillis, other.timeoutInMillis)
&& Objects.equals(trackScores, other.trackScores)
&& Objects.equals(version, other.version);
&& Objects.equals(version, other.version)
&& Objects.equals(profile, other.profile);
}
}

View File

@ -43,7 +43,6 @@ import org.elasticsearch.script.ScriptService;
import org.elasticsearch.search.aggregations.InternalAggregation;
import org.elasticsearch.search.aggregations.InternalAggregation.ReduceContext;
import org.elasticsearch.search.aggregations.InternalAggregations;
import org.elasticsearch.search.aggregations.pipeline.PipelineAggregator;
import org.elasticsearch.search.aggregations.pipeline.SiblingPipelineAggregator;
import org.elasticsearch.search.dfs.AggregatedDfs;
import org.elasticsearch.search.dfs.DfsSearchResult;
@ -52,9 +51,11 @@ import org.elasticsearch.search.fetch.FetchSearchResultProvider;
import org.elasticsearch.search.internal.InternalSearchHit;
import org.elasticsearch.search.internal.InternalSearchHits;
import org.elasticsearch.search.internal.InternalSearchResponse;
import org.elasticsearch.search.profile.InternalProfileShardResults;
import org.elasticsearch.search.query.QuerySearchResult;
import org.elasticsearch.search.query.QuerySearchResultProvider;
import org.elasticsearch.search.suggest.Suggest;
import org.elasticsearch.search.profile.ProfileShardResult;
import java.io.IOException;
import java.util.ArrayList;
@ -410,6 +411,17 @@ public class SearchPhaseController extends AbstractComponent {
}
}
//Collect profile results
InternalProfileShardResults shardResults = null;
if (!queryResults.isEmpty() && firstResult.profileResults() != null) {
Map<String, List<ProfileShardResult>> profileResults = new HashMap<>(queryResults.size());
for (AtomicArray.Entry<? extends QuerySearchResultProvider> entry : queryResults) {
String key = entry.value.queryResult().shardTarget().toString();
profileResults.put(key, entry.value.queryResult().profileResults());
}
shardResults = new InternalProfileShardResults(profileResults);
}
if (aggregations != null) {
List<SiblingPipelineAggregator> pipelineAggregators = firstResult.pipelineAggregators();
if (pipelineAggregators != null) {
@ -427,7 +439,7 @@ public class SearchPhaseController extends AbstractComponent {
InternalSearchHits searchHits = new InternalSearchHits(hits.toArray(new InternalSearchHit[hits.size()]), totalHits, maxScore);
return new InternalSearchResponse(searchHits, aggregations, suggest, timedOut, terminatedEarly);
return new InternalSearchResponse(searchHits, aggregations, suggest, shardResults, timedOut, terminatedEarly);
}
}

View File

@ -26,6 +26,9 @@ import org.apache.lucene.search.*;
import org.elasticsearch.common.lease.Releasable;
import org.elasticsearch.index.engine.Engine;
import org.elasticsearch.search.dfs.AggregatedDfs;
import org.elasticsearch.search.profile.ProfileBreakdown;
import org.elasticsearch.search.profile.ProfileWeight;
import org.elasticsearch.search.profile.Profiler;
import java.io.IOException;
@ -43,26 +46,44 @@ public class ContextIndexSearcher extends IndexSearcher implements Releasable {
private final Engine.Searcher engineSearcher;
public ContextIndexSearcher(SearchContext searchContext, Engine.Searcher searcher) {
// TODO revisit moving the profiler to inheritance or wrapping model in the future
private Profiler profiler;
public ContextIndexSearcher(Engine.Searcher searcher,
QueryCache queryCache, QueryCachingPolicy queryCachingPolicy) {
super(searcher.reader());
in = searcher.searcher();
engineSearcher = searcher;
setSimilarity(searcher.searcher().getSimilarity(true));
setQueryCache(searchContext.getQueryCache());
setQueryCachingPolicy(searchContext.indexShard().getQueryCachingPolicy());
setQueryCache(queryCache);
setQueryCachingPolicy(queryCachingPolicy);
}
@Override
public void close() {
}
public void setProfiler(Profiler profiler) {
this.profiler = profiler;
}
public void setAggregatedDfs(AggregatedDfs aggregatedDfs) {
this.aggregatedDfs = aggregatedDfs;
}
@Override
public Query rewrite(Query original) throws IOException {
if (profiler != null) {
profiler.startRewriteTime();
}
try {
return in.rewrite(original);
} finally {
if (profiler != null) {
profiler.stopAndAddRewriteTime();
}
}
}
@Override
@ -72,9 +93,35 @@ public class ContextIndexSearcher extends IndexSearcher implements Releasable {
if (aggregatedDfs != null && needsScores) {
// if scores are needed and we have dfs data then use it
return super.createNormalizedWeight(query, needsScores);
}
} else if (profiler != null) {
// we need to use the createWeight method to insert the wrappers
return super.createNormalizedWeight(query, needsScores);
} else {
return in.createNormalizedWeight(query, needsScores);
}
}
@Override
public Weight createWeight(Query query, boolean needsScores) throws IOException {
if (profiler != null) {
// createWeight() is called for each query in the tree, so we tell the queryProfiler
// each invocation so that it can build an internal representation of the query
// tree
ProfileBreakdown profile = profiler.getQueryBreakdown(query);
profile.startTime(ProfileBreakdown.TimingType.CREATE_WEIGHT);
final Weight weight;
try {
weight = super.createWeight(query, needsScores);
} finally {
profile.stopAndRecordTime();
profiler.pollLastQuery();
}
return new ProfileWeight(query, weight, profile);
} else {
// needs to be 'super', not 'in' in order to use aggregated DFS
return super.createWeight(query, needsScores);
}
}
@Override
public Explanation explain(Query query, int doc) throws IOException {

View File

@ -58,6 +58,8 @@ import org.elasticsearch.search.fetch.source.FetchSourceContext;
import org.elasticsearch.search.highlight.SearchContextHighlight;
import org.elasticsearch.search.lookup.SearchLookup;
import org.elasticsearch.search.query.QueryPhaseExecutionException;
import org.elasticsearch.search.profile.Profiler;
import org.elasticsearch.search.profile.Profilers;
import org.elasticsearch.search.query.QuerySearchResult;
import org.elasticsearch.search.rescore.RescoreSearchContext;
import org.elasticsearch.search.suggest.SuggestionSearchContext;
@ -129,10 +131,10 @@ public class DefaultSearchContext extends SearchContext {
private List<RescoreSearchContext> rescore;
private SearchLookup searchLookup;
private volatile long keepAlive;
private ScoreDoc lastEmittedDoc;
private final long originNanoTime = System.nanoTime();
private volatile long lastAccessTime = -1;
private InnerHitsContext innerHitsContext;
private Profilers profilers;
private final Map<String, FetchSubPhaseContext> subPhaseContexts = new HashMap<>();
private final Map<Class<?>, Collector> queryCollectors = new HashMap<>();
@ -158,7 +160,7 @@ public class DefaultSearchContext extends SearchContext {
this.fetchResult = new FetchSearchResult(id, shardTarget);
this.indexShard = indexShard;
this.indexService = indexService;
this.searcher = new ContextIndexSearcher(this, engineSearcher);
this.searcher = new ContextIndexSearcher(engineSearcher, indexService.cache().query(), indexShard.getQueryCachingPolicy());
this.timeEstimateCounter = timeEstimateCounter;
this.timeoutInMillis = timeout.millis();
}
@ -724,5 +726,11 @@ public class DefaultSearchContext extends SearchContext {
}
@Override
public QueryCache getQueryCache() { return indexService.cache().query();}
public Profilers getProfilers() {
return profilers;
}
public void setProfilers(Profilers profilers) {
this.profilers = profilers;
}
}

View File

@ -29,7 +29,6 @@ import org.elasticsearch.common.ParseFieldMatcher;
import org.elasticsearch.common.util.BigArrays;
import org.elasticsearch.index.analysis.AnalysisService;
import org.elasticsearch.index.cache.bitset.BitsetFilterCache;
import org.elasticsearch.index.cache.query.QueryCache;
import org.elasticsearch.index.fielddata.IndexFieldDataService;
import org.elasticsearch.index.mapper.MappedFieldType;
import org.elasticsearch.index.mapper.MapperService;
@ -49,6 +48,7 @@ import org.elasticsearch.search.fetch.script.ScriptFieldsContext;
import org.elasticsearch.search.fetch.source.FetchSourceContext;
import org.elasticsearch.search.highlight.SearchContextHighlight;
import org.elasticsearch.search.lookup.SearchLookup;
import org.elasticsearch.search.profile.Profilers;
import org.elasticsearch.search.query.QuerySearchResult;
import org.elasticsearch.search.rescore.RescoreSearchContext;
import org.elasticsearch.search.suggest.SuggestionSearchContext;
@ -517,8 +517,11 @@ public abstract class FilteredSearchContext extends SearchContext {
}
@Override
public Map<Class<?>, Collector> queryCollectors() { return in.queryCollectors();}
public Profilers getProfilers() {
return in.getProfilers();
}
@Override
public QueryCache getQueryCache() { return in.getQueryCache();}
public Map<Class<?>, Collector> queryCollectors() { return in.queryCollectors();}
}

View File

@ -28,9 +28,14 @@ import org.elasticsearch.common.xcontent.XContentBuilder;
import org.elasticsearch.search.SearchHits;
import org.elasticsearch.search.aggregations.Aggregations;
import org.elasticsearch.search.aggregations.InternalAggregations;
import org.elasticsearch.search.profile.InternalProfileShardResults;
import org.elasticsearch.search.profile.ProfileShardResult;
import org.elasticsearch.search.suggest.Suggest;
import java.io.IOException;
import java.util.Collections;
import java.util.List;
import java.util.Map;
import static org.elasticsearch.search.internal.InternalSearchHits.readSearchHits;
@ -40,7 +45,7 @@ import static org.elasticsearch.search.internal.InternalSearchHits.readSearchHit
public class InternalSearchResponse implements Streamable, ToXContent {
public static InternalSearchResponse empty() {
return new InternalSearchResponse(InternalSearchHits.empty(), null, null, false, null);
return new InternalSearchResponse(InternalSearchHits.empty(), null, null, null, false, null);
}
private InternalSearchHits hits;
@ -49,6 +54,8 @@ public class InternalSearchResponse implements Streamable, ToXContent {
private Suggest suggest;
private InternalProfileShardResults profileResults;
private boolean timedOut;
private Boolean terminatedEarly = null;
@ -56,10 +63,12 @@ public class InternalSearchResponse implements Streamable, ToXContent {
private InternalSearchResponse() {
}
public InternalSearchResponse(InternalSearchHits hits, InternalAggregations aggregations, Suggest suggest, boolean timedOut, Boolean terminatedEarly) {
public InternalSearchResponse(InternalSearchHits hits, InternalAggregations aggregations, Suggest suggest,
InternalProfileShardResults profileResults, boolean timedOut, Boolean terminatedEarly) {
this.hits = hits;
this.aggregations = aggregations;
this.suggest = suggest;
this.profileResults = profileResults;
this.timedOut = timedOut;
this.terminatedEarly = terminatedEarly;
}
@ -84,6 +93,19 @@ public class InternalSearchResponse implements Streamable, ToXContent {
return suggest;
}
/**
* Returns the profile results for this search response (including all shards).
* An empty map is returned if profiling was not enabled
*
* @return Profile results
*/
public Map<String, List<ProfileShardResult>> profile() {
if (profileResults == null) {
return Collections.emptyMap();
}
return profileResults.getShardResults();
}
@Override
public XContentBuilder toXContent(XContentBuilder builder, Params params) throws IOException {
hits.toXContent(builder, params);
@ -93,6 +115,9 @@ public class InternalSearchResponse implements Streamable, ToXContent {
if (suggest != null) {
suggest.toXContent(builder, params);
}
if (profileResults != null) {
profileResults.toXContent(builder, params);
}
return builder;
}
@ -114,6 +139,12 @@ public class InternalSearchResponse implements Streamable, ToXContent {
timedOut = in.readBoolean();
terminatedEarly = in.readOptionalBoolean();
if (in.getVersion().onOrAfter(Version.V_2_2_0) && in.readBoolean()) {
profileResults = new InternalProfileShardResults(in);
} else {
profileResults = null;
}
}
@Override
@ -134,5 +165,14 @@ public class InternalSearchResponse implements Streamable, ToXContent {
out.writeBoolean(timedOut);
out.writeOptionalBoolean(terminatedEarly);
if (out.getVersion().onOrAfter(Version.V_2_2_0)) {
if (profileResults == null) {
out.writeBoolean(false);
} else {
out.writeBoolean(true);
profileResults.writeTo(out);
}
}
}
}

View File

@ -35,7 +35,6 @@ import org.elasticsearch.common.util.BigArrays;
import org.elasticsearch.common.util.iterable.Iterables;
import org.elasticsearch.index.analysis.AnalysisService;
import org.elasticsearch.index.cache.bitset.BitsetFilterCache;
import org.elasticsearch.index.cache.query.QueryCache;
import org.elasticsearch.index.fielddata.IndexFieldDataService;
import org.elasticsearch.index.mapper.MappedFieldType;
import org.elasticsearch.index.mapper.MapperService;
@ -56,6 +55,7 @@ import org.elasticsearch.search.fetch.script.ScriptFieldsContext;
import org.elasticsearch.search.fetch.source.FetchSourceContext;
import org.elasticsearch.search.highlight.SearchContextHighlight;
import org.elasticsearch.search.lookup.SearchLookup;
import org.elasticsearch.search.profile.Profilers;
import org.elasticsearch.search.query.QuerySearchResult;
import org.elasticsearch.search.rescore.RescoreSearchContext;
import org.elasticsearch.search.suggest.SuggestionSearchContext;
@ -303,6 +303,11 @@ public abstract class SearchContext extends DelegatingHasContextAndHeaders imple
public abstract FetchSearchResult fetchResult();
/**
* Return a handle over the profilers for the current search request, or {@code null} if profiling is not enabled.
*/
public abstract Profilers getProfilers();
/**
* Schedule the release of a resource. The time when {@link Releasable#close()} will be called on this object
* is function of the provided {@link Lifetime}.
@ -367,5 +372,4 @@ public abstract class SearchContext extends DelegatingHasContextAndHeaders imple
CONTEXT
}
public abstract QueryCache getQueryCache();
}

View File

@ -71,6 +71,8 @@ public class ShardSearchLocalRequest extends ContextAndHeaderHolder implements S
private Boolean requestCache;
private long nowInMillis;
private boolean profile;
ShardSearchLocalRequest() {
}
@ -165,6 +167,16 @@ public class ShardSearchLocalRequest extends ContextAndHeaderHolder implements S
return scroll;
}
@Override
public void setProfile(boolean profile) {
this.profile = profile;
}
@Override
public boolean isProfile() {
return profile;
}
@SuppressWarnings("unchecked")
protected void innerReadFrom(StreamInput in) throws IOException {
index = in.readString();

View File

@ -59,6 +59,17 @@ public interface ShardSearchRequest extends HasContextAndHeaders {
Scroll scroll();
/**
* Sets if this shard search needs to be profiled or not
* @param profile True if the shard should be profiled
*/
void setProfile(boolean profile);
/**
* Returns true if this shard search is being profiled or not
*/
boolean isProfile();
/**
* Returns the cache key for this shard search request, based on its content
*/

View File

@ -150,4 +150,14 @@ public class ShardSearchTransportRequest extends TransportRequest implements Sha
public BytesReference cacheKey() throws IOException {
return shardSearchLocalRequest.cacheKey();
}
@Override
public void setProfile(boolean profile) {
shardSearchLocalRequest.setProfile(profile);
}
@Override
public boolean isProfile() {
return shardSearchLocalRequest.isProfile();
}
}

View File

@ -0,0 +1,156 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.search.profile;
import org.elasticsearch.common.ParseField;
import org.elasticsearch.common.io.stream.StreamInput;
import org.elasticsearch.common.io.stream.StreamOutput;
import org.elasticsearch.common.io.stream.Writeable;
import org.elasticsearch.common.xcontent.ToXContent;
import org.elasticsearch.common.xcontent.XContentBuilder;
import java.io.IOException;
import java.util.ArrayList;
import java.util.List;
import java.util.Locale;
/**
* Public interface and serialization container for profiled timings of the
* Collectors used in the search. Children CollectorResult's may be
* embedded inside of a parent CollectorResult
*/
public class CollectorResult implements ToXContent, Writeable {
public static final String REASON_SEARCH_COUNT = "search_count";
public static final String REASON_SEARCH_TOP_HITS = "search_top_hits";
public static final String REASON_SEARCH_TERMINATE_AFTER_COUNT = "search_terminate_after_count";
public static final String REASON_SEARCH_POST_FILTER = "search_post_filter";
public static final String REASON_SEARCH_MIN_SCORE = "search_min_score";
public static final String REASON_SEARCH_MULTI = "search_multi";
public static final String REASON_SEARCH_TIMEOUT = "search_timeout";
public static final String REASON_AGGREGATION = "aggregation";
public static final String REASON_AGGREGATION_GLOBAL = "aggregation_global";
private static final ParseField NAME = new ParseField("name");
private static final ParseField REASON = new ParseField("reason");
private static final ParseField TIME = new ParseField("time");
private static final ParseField CHILDREN = new ParseField("children");
/**
* A more friendly representation of the Collector's class name
*/
private final String collectorName;
/**
* A "hint" to help provide some context about this Collector
*/
private final String reason;
/**
* The total elapsed time for this Collector
*/
private final Long time;
/**
* A list of children collectors "embedded" inside this collector
*/
private List<CollectorResult> children;
public CollectorResult(String collectorName, String reason, Long time, List<CollectorResult> children) {
this.collectorName = collectorName;
this.reason = reason;
this.time = time;
this.children = children;
}
public CollectorResult(StreamInput in) throws IOException {
this.collectorName = in.readString();
this.reason = in.readString();
this.time = in.readLong();
int size = in.readVInt();
this.children = new ArrayList<>(size);
for (int i = 0; i < size; i++) {
CollectorResult child = new CollectorResult(in);
this.children.add(child);
}
}
/**
* @return the profiled time for this collector (inclusive of children)
*/
public long getTime() {
return this.time;
}
/**
* @return a human readable "hint" about what this collector was used for
*/
public String getReason() {
return this.reason;
}
/**
* @return the lucene class name of the collector
*/
public String getName() {
return this.collectorName;
}
/**
* @return a list of children collectors
*/
public List<CollectorResult> getProfiledChildren() {
return children;
}
@Override
public XContentBuilder toXContent(XContentBuilder builder, ToXContent.Params params) throws IOException {
builder = builder.startObject()
.field(NAME.getPreferredName(), toString())
.field(REASON.getPreferredName(), reason)
.field(TIME.getPreferredName(), String.format(Locale.US, "%.10gms", (double) (getTime() / 1000000.0)));
if (!children.isEmpty()) {
builder = builder.startArray(CHILDREN.getPreferredName());
for (CollectorResult child : children) {
builder = child.toXContent(builder, params);
}
builder = builder.endArray();
}
builder = builder.endObject();
return builder;
}
@Override
public void writeTo(StreamOutput out) throws IOException {
out.writeString(collectorName);
out.writeString(reason);
out.writeLong(time);
out.writeVInt(children.size());
for (CollectorResult child : children) {
child.writeTo(out);
}
}
@Override
public Object readFrom(StreamInput in) throws IOException {
return new CollectorResult(in);
}
}

View File

@ -0,0 +1,135 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.search.profile;
import org.apache.lucene.index.LeafReaderContext;
import org.apache.lucene.search.Collector;
import org.apache.lucene.search.LeafCollector;
import java.io.IOException;
import java.util.ArrayList;
import java.util.List;
/**
* This class wraps a Lucene Collector and times the execution of:
* - setScorer()
* - collect()
* - doSetNextReader()
* - needsScores()
*
* InternalProfiler facilitates the linking of the the Collector graph
*/
public class InternalProfileCollector implements Collector {
/**
* A more friendly representation of the Collector's class name
*/
private final String collectorName;
/**
* A "hint" to help provide some context about this Collector
*/
private final String reason;
/** The wrapped collector */
private final ProfileCollector collector;
/**
* A list of "embedded" children collectors
*/
private final List<InternalProfileCollector> children;
public InternalProfileCollector(Collector collector, String reason, List<InternalProfileCollector> children) {
this.collector = new ProfileCollector(collector);
this.reason = reason;
this.collectorName = deriveCollectorName(collector);
this.children = children;
}
/**
* @return the profiled time for this collector (inclusive of children)
*/
public long getTime() {
return collector.getTime();
}
/**
* @return a human readable "hint" about what this collector was used for
*/
public String getReason() {
return this.reason;
}
/**
* @return the lucene class name of the collector
*/
public String getName() {
return this.collectorName;
}
/**
* Creates a human-friendly representation of the Collector name.
*
* Bucket Collectors use the aggregation name in their toString() method,
* which makes the profiled output a bit nicer.
*
* @param c The Collector to derive a name from
* @return A (hopefully) prettier name
*/
private String deriveCollectorName(Collector c) {
String s = c.getClass().getSimpleName();
// MutiCollector which wraps multiple BucketCollectors is generated
// via an anonymous class, so this corrects the lack of a name by
// asking the enclosingClass
if (s.equals("")) {
s = c.getClass().getEnclosingClass().getSimpleName();
}
// Aggregation collector toString()'s include the user-defined agg name
if (reason.equals(CollectorResult.REASON_AGGREGATION) || reason.equals(CollectorResult.REASON_AGGREGATION_GLOBAL)) {
s += ": [" + c.toString() + "]";
}
return s;
}
@Override
public LeafCollector getLeafCollector(LeafReaderContext context) throws IOException {
return collector.getLeafCollector(context);
}
@Override
public boolean needsScores() {
return collector.needsScores();
}
public CollectorResult getCollectorTree() {
return InternalProfileCollector.doGetCollectorTree(this);
}
private static CollectorResult doGetCollectorTree(InternalProfileCollector collector) {
List<CollectorResult> childResults = new ArrayList<>(collector.children.size());
for (InternalProfileCollector child : collector.children) {
CollectorResult result = doGetCollectorTree(child);
childResults.add(result);
}
return new CollectorResult(collector.getName(), collector.getReason(), collector.getTime(), childResults);
}
}

View File

@ -0,0 +1,89 @@
package org.elasticsearch.search.profile;
import org.elasticsearch.common.io.stream.StreamInput;
import org.elasticsearch.common.io.stream.StreamOutput;
import org.elasticsearch.common.io.stream.Writeable;
import org.elasticsearch.common.xcontent.ToXContent;
import org.elasticsearch.common.xcontent.XContentBuilder;
import java.io.IOException;
import java.util.*;
import java.util.stream.Collectors;
/**
* A container class to hold all the profile results across all shards. Internally
* holds a map of shard ID -&gt; Profiled results
*/
public final class InternalProfileShardResults implements Writeable<InternalProfileShardResults>, ToXContent{
private Map<String, List<ProfileShardResult>> shardResults;
public InternalProfileShardResults(Map<String, List<ProfileShardResult>> shardResults) {
Map<String, List<ProfileShardResult>> transformed =
shardResults.entrySet()
.stream()
.collect(Collectors.toMap(
Map.Entry::getKey,
e -> Collections.unmodifiableList(e.getValue()))
);
this.shardResults = Collections.unmodifiableMap(transformed);
}
public InternalProfileShardResults(StreamInput in) throws IOException {
int size = in.readInt();
shardResults = new HashMap<>(size);
for (int i = 0; i < size; i++) {
String key = in.readString();
int shardResultsSize = in.readInt();
List<ProfileShardResult> shardResult = new ArrayList<>(shardResultsSize);
for (int j = 0; j < shardResultsSize; j++) {
ProfileShardResult result = new ProfileShardResult(in);
shardResult.add(result);
}
shardResults.put(key, shardResult);
}
}
public Map<String, List<ProfileShardResult>> getShardResults() {
return this.shardResults;
}
@Override
public InternalProfileShardResults readFrom(StreamInput in) throws IOException {
return new InternalProfileShardResults(in);
}
@Override
public void writeTo(StreamOutput out) throws IOException {
out.writeInt(shardResults.size());
for (Map.Entry<String, List<ProfileShardResult>> entry : shardResults.entrySet()) {
out.writeString(entry.getKey());
out.writeInt(entry.getValue().size());
for (ProfileShardResult result : entry.getValue()) {
result.writeTo(out);
}
}
}
@Override
public XContentBuilder toXContent(XContentBuilder builder, Params params) throws IOException {
builder.startObject("profile").startArray("shards");
for (Map.Entry<String, List<ProfileShardResult>> entry : shardResults.entrySet()) {
builder.startObject().field("id",entry.getKey()).startArray("searches");
for (ProfileShardResult result : entry.getValue()) {
builder.startObject();
result.toXContent(builder, params);
builder.endObject();
}
builder.endArray().endObject();
}
builder.endArray().endObject();
return builder;
}
}

View File

@ -0,0 +1,235 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.search.profile;
import org.apache.lucene.search.Query;
import java.util.*;
import java.util.concurrent.LinkedBlockingDeque;
/**
* This class tracks the dependency tree for queries (scoring and rewriting) and
* generates {@link ProfileBreakdown} for each node in the tree. It also finalizes the tree
* and returns a list of {@link ProfileResult} that can be serialized back to the client
*/
final class InternalProfileTree {
private ArrayList<ProfileBreakdown> timings;
/** Maps the Query to it's list of children. This is basically the dependency tree */
private ArrayList<ArrayList<Integer>> tree;
/** A list of the original queries, keyed by index position */
private ArrayList<Query> queries;
/** A list of top-level "roots". Each root can have its own tree of profiles */
private ArrayList<Integer> roots;
/** Rewrite time */
private long rewriteTime;
private long rewriteScratch;
/** A temporary stack used to record where we are in the dependency tree. Only used by scoring queries */
private Deque<Integer> stack;
private int currentToken = 0;
public InternalProfileTree() {
timings = new ArrayList<>(10);
stack = new LinkedBlockingDeque<>(10);
tree = new ArrayList<>(10);
queries = new ArrayList<>(10);
roots = new ArrayList<>(10);
}
/**
* Returns a {@link ProfileBreakdown} for a scoring query. Scoring queries (e.g. those
* that are past the rewrite phase and are now being wrapped by createWeight() ) follow
* a recursive progression. We can track the dependency tree by a simple stack
*
* The only hiccup is that the first scoring query will be identical to the last rewritten
* query, so we need to take special care to fix that
*
* @param query The scoring query we wish to profile
* @return A ProfileBreakdown for this query
*/
public ProfileBreakdown getQueryBreakdown(Query query) {
int token = currentToken;
boolean stackEmpty = stack.isEmpty();
// If the stack is empty, we are a new root query
if (stackEmpty) {
// We couldn't find a rewritten query to attach to, so just add it as a
// top-level root. This is just a precaution: it really shouldn't happen.
// We would only get here if a top-level query that never rewrites for some reason.
roots.add(token);
// Increment the token since we are adding a new node, but notably, do not
// updateParent() because this was added as a root
currentToken += 1;
stack.add(token);
return addDependencyNode(query, token);
}
updateParent(token);
// Increment the token since we are adding a new node
currentToken += 1;
stack.add(token);
return addDependencyNode(query, token);
}
/**
* Begin timing a query for a specific Timing context
*/
public void startRewriteTime() {
assert rewriteScratch == 0;
rewriteScratch = System.nanoTime();
}
/**
* Halt the timing process and add the elapsed rewriting time.
* startRewriteTime() must be called for a particular context prior to calling
* stopAndAddRewriteTime(), otherwise the elapsed time will be negative and
* nonsensical
*
* @return The elapsed time
*/
public long stopAndAddRewriteTime() {
long time = Math.max(1, System.nanoTime() - rewriteScratch);
rewriteTime += time;
rewriteScratch = 0;
return time;
}
/**
* Helper method to add a new node to the dependency tree.
*
* Initializes a new list in the dependency tree, saves the query and
* generates a new {@link ProfileBreakdown} to track the timings
* of this query
*
* @param query The query to profile
* @param token The assigned token for this query
* @return A ProfileBreakdown to profile this query
*/
private ProfileBreakdown addDependencyNode(Query query, int token) {
// Add a new slot in the dependency tree
tree.add(new ArrayList<>(5));
// Save our query for lookup later
queries.add(query);
ProfileBreakdown queryTimings = new ProfileBreakdown();
timings.add(token, queryTimings);
return queryTimings;
}
/**
* Removes the last (e.g. most recent) value on the stack
*/
public void pollLast() {
stack.pollLast();
}
/**
* After the query has been run and profiled, we need to merge the flat timing map
* with the dependency graph to build a data structure that mirrors the original
* query tree
*
* @return a hierarchical representation of the profiled query tree
*/
public List<ProfileResult> getQueryTree() {
ArrayList<ProfileResult> results = new ArrayList<>(5);
for (Integer root : roots) {
results.add(doGetQueryTree(root));
}
return results;
}
/**
* Recursive helper to finalize a node in the dependency tree
* @param token The node we are currently finalizing
* @return A hierarchical representation of the tree inclusive of children at this level
*/
private ProfileResult doGetQueryTree(int token) {
Query query = queries.get(token);
ProfileBreakdown breakdown = timings.get(token);
Map<String, Long> timings = breakdown.toTimingMap();
List<Integer> children = tree.get(token);
List<ProfileResult> childrenProfileResults = Collections.emptyList();
if (children != null) {
childrenProfileResults = new ArrayList<>(children.size());
for (Integer child : children) {
ProfileResult childNode = doGetQueryTree(child);
childrenProfileResults.add(childNode);
}
}
// TODO this would be better done bottom-up instead of top-down to avoid
// calculating the same times over and over...but worth the effort?
long nodeTime = getNodeTime(timings, childrenProfileResults);
String queryDescription = query.getClass().getSimpleName();
String luceneName = query.toString();
return new ProfileResult(queryDescription, luceneName, timings, childrenProfileResults, nodeTime);
}
public long getRewriteTime() {
return rewriteTime;
}
/**
* Internal helper to add a child to the current parent node
*
* @param childToken The child to add to the current parent
*/
private void updateParent(int childToken) {
Integer parent = stack.peekLast();
ArrayList<Integer> parentNode = tree.get(parent);
parentNode.add(childToken);
tree.set(parent, parentNode);
}
/**
* Internal helper to calculate the time of a node, inclusive of children
*
* @param timings A map of breakdown timing for the node
* @param children All children profile results at this node
* @return The total time at this node, inclusive of children
*/
private static long getNodeTime(Map<String, Long> timings, List<ProfileResult> children) {
long nodeTime = 0;
for (long time : timings.values()) {
nodeTime += time;
}
// Then add up our children
for (ProfileResult child : children) {
nodeTime += getNodeTime(child.getTimeBreakdown(), child.getProfiledChildren());
}
return nodeTime;
}
}

View File

@ -0,0 +1,113 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.search.profile;
import java.util.Collections;
import java.util.HashMap;
import java.util.Locale;
import java.util.Map;
/**
* A record of timings for the various operations that may happen during query execution.
* A node's time may be composed of several internal attributes (rewriting, weighting,
* scoring, etc).
*/
public final class ProfileBreakdown {
/** Enumeration of all supported timing types. */
public enum TimingType {
CREATE_WEIGHT,
BUILD_SCORER,
NEXT_DOC,
ADVANCE,
MATCH,
SCORE;
@Override
public String toString() {
return name().toLowerCase(Locale.ROOT);
}
}
/**
* The accumulated timings for this query node
*/
private final long[] timings;
/** Scrach to store the current timing type. */
private TimingType currentTimingType;
/**
* The temporary scratch space for holding start-times
*/
private long scratch;
/** Sole constructor. */
public ProfileBreakdown() {
timings = new long[TimingType.values().length];
}
/**
* Begin timing a query for a specific Timing context
* @param timing The timing context being profiled
*/
public void startTime(TimingType timing) {
assert currentTimingType == null;
assert scratch == 0;
currentTimingType = timing;
scratch = System.nanoTime();
}
/**
* Halt the timing process and save the elapsed time.
* startTime() must be called for a particular context prior to calling
* stopAndRecordTime(), otherwise the elapsed time will be negative and
* nonsensical
*
* @return The elapsed time
*/
public long stopAndRecordTime() {
long time = Math.max(1, System.nanoTime() - scratch);
timings[currentTimingType.ordinal()] += time;
currentTimingType = null;
scratch = 0L;
return time;
}
/** Convert this record to a map from {@link TimingType} to times. */
public Map<String, Long> toTimingMap() {
Map<String, Long> map = new HashMap<>();
for (TimingType timingType : TimingType.values()) {
map.put(timingType.toString(), timings[timingType.ordinal()]);
}
return Collections.unmodifiableMap(map);
}
/**
* Add <code>other</code>'s timings into this breakdown
* @param other Another Breakdown to merge with this one
*/
public void merge(ProfileBreakdown other) {
assert(timings.length == other.timings.length);
for (int i = 0; i < timings.length; ++i) {
timings[i] += other.timings[i];
}
}
}

View File

@ -0,0 +1,94 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.search.profile;
import org.apache.lucene.index.LeafReaderContext;
import org.apache.lucene.search.Collector;
import org.apache.lucene.search.FilterCollector;
import org.apache.lucene.search.FilterLeafCollector;
import org.apache.lucene.search.LeafCollector;
import org.apache.lucene.search.Scorer;
import java.io.IOException;
/** A collector that profiles how much time is spent calling it. */
final class ProfileCollector extends FilterCollector {
private long time;
/** Sole constructor. */
public ProfileCollector(Collector in) {
super(in);
}
/** Return the wrapped collector. */
public Collector getDelegate() {
return in;
}
@Override
public boolean needsScores() {
final long start = System.nanoTime();
try {
return super.needsScores();
} finally {
time += Math.max(1, System.nanoTime() - start);
}
}
@Override
public LeafCollector getLeafCollector(LeafReaderContext context) throws IOException {
final long start = System.nanoTime();
final LeafCollector inLeafCollector;
try {
inLeafCollector = super.getLeafCollector(context);
} finally {
time += Math.max(1, System.nanoTime() - start);
}
return new FilterLeafCollector(inLeafCollector) {
@Override
public void collect(int doc) throws IOException {
final long start = System.nanoTime();
try {
super.collect(doc);
} finally {
time += Math.max(1, System.nanoTime() - start);
}
}
@Override
public void setScorer(Scorer scorer) throws IOException {
final long start = System.nanoTime();
try {
super.setScorer(scorer);
} finally {
time += Math.max(1, System.nanoTime() - start);
}
}
};
}
/** Return the total time spent on this collector. */
public long getTime() {
return time;
}
}

View File

@ -0,0 +1,165 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.search.profile;
import org.elasticsearch.common.ParseField;
import org.elasticsearch.common.io.stream.StreamInput;
import org.elasticsearch.common.io.stream.StreamOutput;
import org.elasticsearch.common.io.stream.Writeable;
import org.elasticsearch.common.xcontent.ToXContent;
import org.elasticsearch.common.xcontent.XContentBuilder;
import java.io.IOException;
import java.util.ArrayList;
import java.util.Collections;
import java.util.HashMap;
import java.util.List;
import java.util.Locale;
import java.util.Map;
/**
* This class is the internal representation of a profiled Query, corresponding
* to a single node in the query tree. It is built after the query has finished executing
* and is merely a structured representation, rather than the entity that collects the timing
* profile (see InternalProfiler for that)
*
* Each InternalProfileResult has a List of InternalProfileResults, which will contain
* "children" queries if applicable
*/
final class ProfileResult implements Writeable<ProfileResult>, ToXContent {
private static final ParseField QUERY_TYPE = new ParseField("query_type");
private static final ParseField LUCENE_DESCRIPTION = new ParseField("lucene");
private static final ParseField NODE_TIME = new ParseField("time");
private static final ParseField CHILDREN = new ParseField("children");
private static final ParseField BREAKDOWN = new ParseField("breakdown");
private final String queryType;
private final String luceneDescription;
private final Map<String, Long> timings;
private final long nodeTime;
private final List<ProfileResult> children;
public ProfileResult(String queryType, String luceneDescription, Map<String, Long> timings, List<ProfileResult> children, long nodeTime) {
this.queryType = queryType;
this.luceneDescription = luceneDescription;
this.timings = timings;
this.children = children;
this.nodeTime = nodeTime;
}
public ProfileResult(StreamInput in) throws IOException{
this.queryType = in.readString();
this.luceneDescription = in.readString();
this.nodeTime = in.readLong();
int timingsSize = in.readVInt();
this.timings = new HashMap<>(timingsSize);
for (int i = 0; i < timingsSize; ++i) {
timings.put(in.readString(), in.readLong());
}
int size = in.readVInt();
this.children = new ArrayList<>(size);
for (int i = 0; i < size; i++) {
children.add(new ProfileResult(in));
}
}
/**
* Retrieve the lucene description of this query (e.g. the "explain" text)
*/
public String getLuceneDescription() {
return luceneDescription;
}
/**
* Retrieve the name of the query (e.g. "TermQuery")
*/
public String getQueryName() {
return queryType;
}
/**
* Returns the timing breakdown for this particular query node
*/
public Map<String, Long> getTimeBreakdown() {
return Collections.unmodifiableMap(timings);
}
/**
* Returns the total time (inclusive of children) for this query node.
*
* @return elapsed time in nanoseconds
*/
public long getTime() {
return nodeTime;
}
/**
* Returns a list of all profiled children queries
*/
public List<ProfileResult> getProfiledChildren() {
return Collections.unmodifiableList(children);
}
@Override
public ProfileResult readFrom(StreamInput in) throws IOException {
return new ProfileResult(in);
}
@Override
public void writeTo(StreamOutput out) throws IOException {
out.writeString(queryType);
out.writeString(luceneDescription);
out.writeLong(nodeTime); // not Vlong because can be negative
out.writeVInt(timings.size());
for (Map.Entry<String, Long> entry : timings.entrySet()) {
out.writeString(entry.getKey());
out.writeLong(entry.getValue());
}
out.writeVInt(children.size());
for (ProfileResult child : children) {
child.writeTo(out);
}
}
@Override
public XContentBuilder toXContent(XContentBuilder builder, Params params) throws IOException {
builder = builder.startObject()
.field(QUERY_TYPE.getPreferredName(), queryType)
.field(LUCENE_DESCRIPTION.getPreferredName(), luceneDescription)
.field(NODE_TIME.getPreferredName(), String.format(Locale.US, "%.10gms", (double)(getTime() / 1000000.0)))
.field(BREAKDOWN.getPreferredName(), timings);
if (!children.isEmpty()) {
builder = builder.startArray(CHILDREN.getPreferredName());
for (ProfileResult child : children) {
builder = child.toXContent(builder, params);
}
builder = builder.endArray();
}
builder = builder.endObject();
return builder;
}
}

View File

@ -0,0 +1,158 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.search.profile;
import org.apache.lucene.search.DocIdSetIterator;
import org.apache.lucene.search.Scorer;
import org.apache.lucene.search.TwoPhaseIterator;
import org.apache.lucene.search.Weight;
import java.io.IOException;
import java.util.Collection;
/**
* {@link Scorer} wrapper that will compute how much time is spent on moving
* the iterator, confirming matches and computing scores.
*/
final class ProfileScorer extends Scorer {
private final Scorer scorer;
private ProfileWeight profileWeight;
private final ProfileBreakdown profile;
ProfileScorer(ProfileWeight w, Scorer scorer, ProfileBreakdown profile) throws IOException {
super(w);
this.scorer = scorer;
this.profileWeight = w;
this.profile = profile;
}
@Override
public int docID() {
return scorer.docID();
}
@Override
public int advance(int target) throws IOException {
profile.startTime(ProfileBreakdown.TimingType.ADVANCE);
try {
return scorer.advance(target);
} finally {
profile.stopAndRecordTime();
}
}
@Override
public int nextDoc() throws IOException {
profile.startTime(ProfileBreakdown.TimingType.NEXT_DOC);
try {
return scorer.nextDoc();
} finally {
profile.stopAndRecordTime();
}
}
@Override
public float score() throws IOException {
profile.startTime(ProfileBreakdown.TimingType.SCORE);
try {
return scorer.score();
} finally {
profile.stopAndRecordTime();
}
}
@Override
public int freq() throws IOException {
return scorer.freq();
}
@Override
public long cost() {
return scorer.cost();
}
@Override
public Weight getWeight() {
return profileWeight;
}
@Override
public Collection<ChildScorer> getChildren() {
return scorer.getChildren();
}
@Override
public TwoPhaseIterator asTwoPhaseIterator() {
final TwoPhaseIterator in = scorer.asTwoPhaseIterator();
if (in == null) {
return null;
}
final DocIdSetIterator inApproximation = in.approximation();
final DocIdSetIterator approximation = new DocIdSetIterator() {
@Override
public int advance(int target) throws IOException {
profile.startTime(ProfileBreakdown.TimingType.ADVANCE);
try {
return inApproximation.advance(target);
} finally {
profile.stopAndRecordTime();
}
}
@Override
public int nextDoc() throws IOException {
profile.startTime(ProfileBreakdown.TimingType.NEXT_DOC);
try {
return inApproximation.nextDoc();
} finally {
profile.stopAndRecordTime();
}
}
@Override
public int docID() {
return inApproximation.docID();
}
@Override
public long cost() {
return inApproximation.cost();
}
};
return new TwoPhaseIterator(approximation) {
@Override
public boolean matches() throws IOException {
profile.startTime(ProfileBreakdown.TimingType.MATCH);
try {
return in.matches();
} finally {
profile.stopAndRecordTime();
}
}
@Override
public float matchCost() {
return in.matchCost();
}
};
}
}

View File

@ -0,0 +1,103 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.search.profile;
import org.elasticsearch.common.io.stream.StreamInput;
import org.elasticsearch.common.io.stream.StreamOutput;
import org.elasticsearch.common.io.stream.Writeable;
import org.elasticsearch.common.xcontent.ToXContent;
import org.elasticsearch.common.xcontent.XContentBuilder;
import java.io.IOException;
import java.util.*;
/**
* A container class to hold the profile results for a single shard in the request.
* Contains a list of query profiles, a collector tree and a total rewrite tree.
*/
public final class ProfileShardResult implements Writeable<ProfileShardResult>, ToXContent {
private final List<ProfileResult> profileResults;
private final CollectorResult profileCollector;
private final long rewriteTime;
public ProfileShardResult(List<ProfileResult> profileResults, long rewriteTime,
CollectorResult profileCollector) {
assert(profileCollector != null);
this.profileResults = profileResults;
this.profileCollector = profileCollector;
this.rewriteTime = rewriteTime;
}
public ProfileShardResult(StreamInput in) throws IOException {
int profileSize = in.readVInt();
profileResults = new ArrayList<>(profileSize);
for (int j = 0; j < profileSize; j++) {
profileResults.add(new ProfileResult(in));
}
profileCollector = new CollectorResult(in);
rewriteTime = in.readLong();
}
public List<ProfileResult> getQueryResults() {
return Collections.unmodifiableList(profileResults);
}
public long getRewriteTime() {
return rewriteTime;
}
public CollectorResult getCollectorResult() {
return profileCollector;
}
@Override
public XContentBuilder toXContent(XContentBuilder builder, Params params) throws IOException {
builder.startArray("query");
for (ProfileResult p : profileResults) {
p.toXContent(builder, params);
}
builder.endArray();
builder.field("rewrite_time", rewriteTime);
builder.startArray("collector");
profileCollector.toXContent(builder, params);
builder.endArray();
return builder;
}
@Override
public ProfileShardResult readFrom(StreamInput in) throws IOException {
return new ProfileShardResult(in);
}
@Override
public void writeTo(StreamOutput out) throws IOException {
out.writeVInt(profileResults.size());
for (ProfileResult p : profileResults) {
p.writeTo(out);
}
profileCollector.writeTo(out);
out.writeLong(rewriteTime);
}
}

View File

@ -0,0 +1,97 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.search.profile;
import org.apache.lucene.index.LeafReaderContext;
import org.apache.lucene.index.Term;
import org.apache.lucene.search.BulkScorer;
import org.apache.lucene.search.Explanation;
import org.apache.lucene.search.Query;
import org.apache.lucene.search.Scorer;
import org.apache.lucene.search.Weight;
import java.io.IOException;
import java.util.Set;
/**
* Weight wrapper that will compute how much time it takes to build the
* {@link Scorer} and then return a {@link Scorer} that is wrapped in
* order to compute timings as well.
*/
public final class ProfileWeight extends Weight {
private final Weight subQueryWeight;
private final ProfileBreakdown profile;
public ProfileWeight(Query query, Weight subQueryWeight, ProfileBreakdown profile) throws IOException {
super(query);
this.subQueryWeight = subQueryWeight;
this.profile = profile;
}
@Override
public Scorer scorer(LeafReaderContext context) throws IOException {
profile.startTime(ProfileBreakdown.TimingType.BUILD_SCORER);
final Scorer subQueryScorer;
try {
subQueryScorer = subQueryWeight.scorer(context);
} finally {
profile.stopAndRecordTime();
}
if (subQueryScorer == null) {
return null;
}
return new ProfileScorer(this, subQueryScorer, profile);
}
@Override
public BulkScorer bulkScorer(LeafReaderContext context) throws IOException {
// We use the default bulk scorer instead of the specialized one. The reason
// is that Lucene's BulkScorers do everything at once: finding matches,
// scoring them and calling the collector, so they make it impossible to
// see where time is spent, which is the purpose of query profiling.
// The default bulk scorer will pull a scorer and iterate over matches,
// this might be a significantly different execution path for some queries
// like disjunctions, but in general this is what is done anyway
return super.bulkScorer(context);
}
@Override
public Explanation explain(LeafReaderContext context, int doc) throws IOException {
return subQueryWeight.explain(context, doc);
}
@Override
public float getValueForNormalization() throws IOException {
return subQueryWeight.getValueForNormalization();
}
@Override
public void normalize(float norm, float topLevelBoost) {
subQueryWeight.normalize(norm, topLevelBoost);
}
@Override
public void extractTerms(Set<Term> set) {
subQueryWeight.extractTerms(set);
}
}

View File

@ -0,0 +1,130 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.search.profile;
import org.apache.lucene.search.Query;
import java.util.*;
/**
* This class acts as a thread-local storage for profiling a query. It also
* builds a representation of the query tree which is built constructed
* "online" as the weights are wrapped by ContextIndexSearcher. This allows us
* to know the relationship between nodes in tree without explicitly
* walking the tree or pre-wrapping everything
*
* A Profiler is associated with every Search, not per Search-Request. E.g. a
* request may execute two searches (query + global agg). A Profiler just
* represents one of those
*/
public final class Profiler {
private final InternalProfileTree queryTree = new InternalProfileTree();
/**
* The root Collector used in the search
*/
private InternalProfileCollector collector;
public Profiler() {}
/** Set the collector that is associated with this profiler. */
public void setCollector(InternalProfileCollector collector) {
if (this.collector != null) {
throw new IllegalStateException("The collector can only be set once.");
}
this.collector = Objects.requireNonNull(collector);
}
/**
* Get the {@link ProfileBreakdown} for the given query, potentially creating it if it did not exist.
* This should only be used for queries that will be undergoing scoring. Do not use it to profile the
* rewriting phase
*/
public ProfileBreakdown getQueryBreakdown(Query query) {
return queryTree.getQueryBreakdown(query);
}
/**
* Begin timing the rewrite phase of a request. All rewrites are accumulated together into a
* single metric
*/
public void startRewriteTime() {
queryTree.startRewriteTime();
}
/**
* Stop recording the current rewrite and add it's time to the total tally, returning the
* cumulative time so far.
*
* @return cumulative rewrite time
*/
public long stopAndAddRewriteTime() {
return queryTree.stopAndAddRewriteTime();
}
/**
* Removes the last (e.g. most recent) query on the stack. This should only be called for scoring
* queries, not rewritten queries
*/
public void pollLastQuery() {
queryTree.pollLast();
}
/**
* @return a hierarchical representation of the profiled query tree
*/
public List<ProfileResult> getQueryTree() {
return queryTree.getQueryTree();
}
/**
* @return total time taken to rewrite all queries in this profile
*/
public long getRewriteTime() {
return queryTree.getRewriteTime();
}
/**
* Return the current root Collector for this search
*/
public CollectorResult getCollector() {
return collector.getCollectorTree();
}
/**
* Helper method to convert Profiler into InternalProfileShardResults, which can be
* serialized to other nodes, emitted as JSON, etc.
*
* @param profilers A list of Profilers to convert into InternalProfileShardResults
* @return A list of corresponding InternalProfileShardResults
*/
public static List<ProfileShardResult> buildShardResults(List<Profiler> profilers) {
List<ProfileShardResult> results = new ArrayList<>(profilers.size());
for (Profiler profiler : profilers) {
ProfileShardResult result = new ProfileShardResult(
profiler.getQueryTree(), profiler.getRewriteTime(), profiler.getCollector());
results.add(result);
}
return results;
}
}

View File

@ -0,0 +1,59 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.search.profile;
import org.elasticsearch.search.internal.ContextIndexSearcher;
import java.util.ArrayList;
import java.util.Collections;
import java.util.List;
/** Wrapper around several {@link Profiler}s that makes management easier. */
public final class Profilers {
private final ContextIndexSearcher searcher;
private final List<Profiler> profilers;
/** Sole constructor. This {@link Profilers} instance will initiall wrap one {@link Profiler}. */
public Profilers(ContextIndexSearcher searcher) {
this.searcher = searcher;
this.profilers = new ArrayList<>();
addProfiler();
}
/** Switch to a new profile. */
public Profiler addProfiler() {
Profiler profiler = new Profiler();
searcher.setProfiler(profiler);
profilers.add(profiler);
return profiler;
}
/** Get the current profiler. */
public Profiler getCurrent() {
return profilers.get(profilers.size() - 1);
}
/** Return the list of all created {@link Profiler}s so far. */
public List<Profiler> getProfilers() {
return Collections.unmodifiableList(profilers);
}
}

View File

@ -52,13 +52,16 @@ import org.elasticsearch.search.SearchService;
import org.elasticsearch.search.aggregations.AggregationPhase;
import org.elasticsearch.search.internal.ScrollContext;
import org.elasticsearch.search.internal.SearchContext;
import org.elasticsearch.search.profile.*;
import org.elasticsearch.search.rescore.RescorePhase;
import org.elasticsearch.search.rescore.RescoreSearchContext;
import org.elasticsearch.search.sort.SortParseElement;
import org.elasticsearch.search.sort.TrackScoresParseElement;
import org.elasticsearch.search.suggest.SuggestPhase;
import java.util.AbstractList;
import java.util.ArrayList;
import java.util.Collections;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
@ -124,6 +127,11 @@ public class QueryPhase implements SearchPhase {
}
suggestPhase.execute(searchContext);
aggregationPhase.execute(searchContext);
if (searchContext.getProfilers() != null) {
List<ProfileShardResult> shardResults = Profiler.buildShardResults(searchContext.getProfilers().getProfilers());
searchContext.queryResult().profileResults(shardResults);
}
}
private static boolean returnsDocsInOrder(Query query, Sort sort) {
@ -147,6 +155,7 @@ public class QueryPhase implements SearchPhase {
QuerySearchResult queryResult = searchContext.queryResult();
queryResult.searchTimedOut(false);
final boolean doProfile = searchContext.getProfilers() != null;
final SearchType searchType = searchContext.searchType();
boolean rescore = false;
try {
@ -162,9 +171,13 @@ public class QueryPhase implements SearchPhase {
Callable<TopDocs> topDocsCallable;
assert query == searcher.rewrite(query); // already rewritten
if (searchContext.size() == 0) { // no matter what the value of from is
final TotalHitCountCollector totalHitCountCollector = new TotalHitCountCollector();
collector = totalHitCountCollector;
if (searchContext.getProfilers() != null) {
collector = new InternalProfileCollector(collector, CollectorResult.REASON_SEARCH_COUNT, Collections.emptyList());
}
topDocsCallable = new Callable<TopDocs>() {
@Override
public TopDocs call() throws Exception {
@ -219,6 +232,9 @@ public class QueryPhase implements SearchPhase {
topDocsCollector = TopScoreDocCollector.create(numDocs, lastEmittedDoc);
}
collector = topDocsCollector;
if (doProfile) {
collector = new InternalProfileCollector(collector, CollectorResult.REASON_SEARCH_TOP_HITS, Collections.emptyList());
}
topDocsCallable = new Callable<TopDocs>() {
@Override
public TopDocs call() throws Exception {
@ -254,27 +270,57 @@ public class QueryPhase implements SearchPhase {
final boolean terminateAfterSet = searchContext.terminateAfter() != SearchContext.DEFAULT_TERMINATE_AFTER;
if (terminateAfterSet) {
final Collector child = collector;
// throws Lucene.EarlyTerminationException when given count is reached
collector = Lucene.wrapCountBasedEarlyTerminatingCollector(collector, searchContext.terminateAfter());
if (doProfile) {
collector = new InternalProfileCollector(collector, CollectorResult.REASON_SEARCH_TERMINATE_AFTER_COUNT,
Collections.singletonList((InternalProfileCollector) child));
}
}
if (searchContext.parsedPostFilter() != null) {
final Collector child = collector;
// this will only get applied to the actual search collector and not
// to any scoped collectors, also, it will only be applied to the main collector
// since that is where the filter should only work
final Weight filterWeight = searcher.createNormalizedWeight(searchContext.parsedPostFilter().query(), false);
collector = new FilteredCollector(collector, filterWeight);
if (doProfile) {
collector = new InternalProfileCollector(collector, CollectorResult.REASON_SEARCH_POST_FILTER,
Collections.singletonList((InternalProfileCollector) child));
}
}
// plug in additional collectors, like aggregations
List<Collector> allCollectors = new ArrayList<>();
allCollectors.add(collector);
allCollectors.addAll(searchContext.queryCollectors().values());
collector = MultiCollector.wrap(allCollectors);
final List<Collector> subCollectors = new ArrayList<>();
subCollectors.add(collector);
subCollectors.addAll(searchContext.queryCollectors().values());
collector = MultiCollector.wrap(subCollectors);
if (doProfile && collector instanceof InternalProfileCollector == false) {
// When there is a single collector to wrap, MultiCollector returns it
// directly, so only wrap in the case that there are several sub collectors
final List<InternalProfileCollector> children = new AbstractList<InternalProfileCollector>() {
@Override
public InternalProfileCollector get(int index) {
return (InternalProfileCollector) subCollectors.get(index);
}
@Override
public int size() {
return subCollectors.size();
}
};
collector = new InternalProfileCollector(collector, CollectorResult.REASON_SEARCH_MULTI, children);
}
// apply the minimum score after multi collector so we filter aggs as well
if (searchContext.minimumScore() != null) {
final Collector child = collector;
collector = new MinimumScoreCollector(collector, searchContext.minimumScore());
if (doProfile) {
collector = new InternalProfileCollector(collector, CollectorResult.REASON_SEARCH_MIN_SCORE,
Collections.singletonList((InternalProfileCollector) child));
}
}
if (collector.getClass() == TotalHitCountCollector.class) {
@ -319,13 +365,21 @@ public class QueryPhase implements SearchPhase {
final boolean timeoutSet = searchContext.timeoutInMillis() != SearchService.NO_TIMEOUT.millis();
if (timeoutSet && collector != null) { // collector might be null if no collection is actually needed
final Collector child = collector;
// TODO: change to use our own counter that uses the scheduler in ThreadPool
// throws TimeLimitingCollector.TimeExceededException when timeout has reached
collector = Lucene.wrapTimeLimitingCollector(collector, searchContext.timeEstimateCounter(), searchContext.timeoutInMillis());
if (doProfile) {
collector = new InternalProfileCollector(collector, CollectorResult.REASON_SEARCH_TIMEOUT,
Collections.singletonList((InternalProfileCollector) child));
}
}
try {
if (collector != null) {
if (doProfile) {
searchContext.getProfilers().getCurrent().setCollector((InternalProfileCollector) collector);
}
searcher.search(query, collector);
}
} catch (TimeLimitingCollector.TimeExceededException e) {
@ -343,7 +397,13 @@ public class QueryPhase implements SearchPhase {
queryResult.topDocs(topDocsCallable.call());
if (searchContext.getProfilers() != null) {
List<ProfileShardResult> shardResults = Profiler.buildShardResults(searchContext.getProfilers().getProfilers());
searchContext.queryResult().profileResults(shardResults);
}
return rescore;
} catch (Throwable e) {
throw new QueryPhaseExecutionException(searchContext, "Failed to execute main query", e);
}

View File

@ -20,6 +20,8 @@
package org.elasticsearch.search.query;
import org.apache.lucene.search.TopDocs;
import org.elasticsearch.Version;
import org.elasticsearch.common.Nullable;
import org.elasticsearch.common.bytes.BytesReference;
import org.elasticsearch.common.io.stream.StreamInput;
import org.elasticsearch.common.io.stream.StreamOutput;
@ -29,6 +31,7 @@ import org.elasticsearch.search.aggregations.InternalAggregations;
import org.elasticsearch.search.aggregations.pipeline.PipelineAggregator;
import org.elasticsearch.search.aggregations.pipeline.PipelineAggregatorStreams;
import org.elasticsearch.search.aggregations.pipeline.SiblingPipelineAggregator;
import org.elasticsearch.search.profile.ProfileShardResult;
import org.elasticsearch.search.suggest.Suggest;
import java.io.IOException;
@ -53,6 +56,7 @@ public class QuerySearchResult extends QuerySearchResultProvider {
private Suggest suggest;
private boolean searchTimedOut;
private Boolean terminatedEarly = null;
private List<ProfileShardResult> profileShardResults;
public QuerySearchResult() {
@ -120,6 +124,22 @@ public class QuerySearchResult extends QuerySearchResultProvider {
this.aggregations = aggregations;
}
/**
* Returns the profiled results for this search, or potentially null if result was empty
* @return The profiled results, or null
*/
public @Nullable List<ProfileShardResult> profileResults() {
return profileShardResults;
}
/**
* Sets the finalized profiling results for this query
* @param shardResults The finalized profile
*/
public void profileResults(List<ProfileShardResult> shardResults) {
this.profileShardResults = shardResults;
}
public List<SiblingPipelineAggregator> pipelineAggregators() {
return pipelineAggregators;
}
@ -191,6 +211,15 @@ public class QuerySearchResult extends QuerySearchResultProvider {
}
searchTimedOut = in.readBoolean();
terminatedEarly = in.readOptionalBoolean();
if (in.getVersion().onOrAfter(Version.V_2_2_0) && in.readBoolean()) {
int profileSize = in.readVInt();
profileShardResults = new ArrayList<>(profileSize);
for (int i = 0; i < profileSize; i++) {
ProfileShardResult result = new ProfileShardResult(in);
profileShardResults.add(result);
}
}
}
@Override
@ -229,5 +258,17 @@ public class QuerySearchResult extends QuerySearchResultProvider {
}
out.writeBoolean(searchTimedOut);
out.writeOptionalBoolean(terminatedEarly);
if (out.getVersion().onOrAfter(Version.V_2_2_0)) {
if (profileShardResults == null) {
out.writeBoolean(false);
} else {
out.writeBoolean(true);
out.writeVInt(profileShardResults.size());
for (ProfileShardResult shardResult : profileShardResults) {
shardResult.writeTo(out);
}
}
}
}
}

View File

@ -57,6 +57,7 @@ import static org.elasticsearch.search.aggregations.AggregationBuilders.min;
import static org.elasticsearch.search.aggregations.AggregationBuilders.range;
import static org.elasticsearch.search.aggregations.pipeline.PipelineAggregatorBuilders.derivative;
import static org.elasticsearch.search.aggregations.pipeline.PipelineAggregatorBuilders.movingAvg;
import static org.elasticsearch.test.hamcrest.DoubleMatcher.nearlyEqual;
import static org.elasticsearch.test.hamcrest.ElasticsearchAssertions.assertSearchResponse;
import static org.hamcrest.Matchers.equalTo;
import static org.hamcrest.Matchers.is;

View File

@ -0,0 +1,173 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.search.profile;
import org.apache.lucene.document.Document;
import org.apache.lucene.document.Field.Store;
import org.apache.lucene.document.StringField;
import org.apache.lucene.index.IndexReader;
import org.apache.lucene.index.RandomIndexWriter;
import org.apache.lucene.index.Term;
import org.apache.lucene.search.IndexSearcher;
import org.apache.lucene.search.LeafCollector;
import org.apache.lucene.search.Query;
import org.apache.lucene.search.RandomApproximationQuery;
import org.apache.lucene.search.Sort;
import org.apache.lucene.search.TermQuery;
import org.apache.lucene.search.TotalHitCountCollector;
import org.apache.lucene.store.Directory;
import org.apache.lucene.util.IOUtils;
import org.apache.lucene.util.TestUtil;
import org.elasticsearch.common.lucene.Lucene;
import org.elasticsearch.index.engine.Engine;
import org.elasticsearch.search.internal.ContextIndexSearcher;
import org.elasticsearch.test.ESTestCase;
import org.junit.AfterClass;
import org.junit.BeforeClass;
import java.io.IOException;
import java.util.List;
import java.util.Map;
import static org.hamcrest.Matchers.equalTo;
import static org.hamcrest.Matchers.greaterThan;
public class ProfileTests extends ESTestCase {
static Directory dir;
static IndexReader reader;
static ContextIndexSearcher searcher;
@BeforeClass
public static void before() throws IOException {
dir = newDirectory();
RandomIndexWriter w = new RandomIndexWriter(random(), dir);
final int numDocs = TestUtil.nextInt(random(), 1, 20);
for (int i = 0; i < numDocs; ++i) {
final int numHoles = random().nextInt(5);
for (int j = 0; j < numHoles; ++j) {
w.addDocument(new Document());
}
Document doc = new Document();
doc.add(new StringField("foo", "bar", Store.NO));
w.addDocument(doc);
}
reader = w.getReader();
w.close();
Engine.Searcher engineSearcher = new Engine.Searcher("test", new IndexSearcher(reader));
searcher = new ContextIndexSearcher(engineSearcher, IndexSearcher.getDefaultQueryCache(), MAYBE_CACHE_POLICY);
}
@AfterClass
public static void after() throws IOException {
IOUtils.close(reader, dir);
dir = null;
reader = null;
searcher = null;
}
public void testBasic() throws IOException {
Profiler profiler = new Profiler();
searcher.setProfiler(profiler);
Query query = new TermQuery(new Term("foo", "bar"));
searcher.search(query, 1);
List<ProfileResult> results = profiler.getQueryTree();
assertEquals(1, results.size());
Map<String, Long> breakdown = results.get(0).getTimeBreakdown();
assertThat(breakdown.get(ProfileBreakdown.TimingType.CREATE_WEIGHT.toString()).longValue(), greaterThan(0L));
assertThat(breakdown.get(ProfileBreakdown.TimingType.BUILD_SCORER.toString()).longValue(), greaterThan(0L));
assertThat(breakdown.get(ProfileBreakdown.TimingType.NEXT_DOC.toString()).longValue(), greaterThan(0L));
assertThat(breakdown.get(ProfileBreakdown.TimingType.ADVANCE.toString()).longValue(), equalTo(0L));
assertThat(breakdown.get(ProfileBreakdown.TimingType.SCORE.toString()).longValue(), greaterThan(0L));
assertThat(breakdown.get(ProfileBreakdown.TimingType.MATCH.toString()).longValue(), equalTo(0L));
long rewriteTime = profiler.getRewriteTime();
assertThat(rewriteTime, greaterThan(0L));
}
public void testNoScoring() throws IOException {
Profiler profiler = new Profiler();
searcher.setProfiler(profiler);
Query query = new TermQuery(new Term("foo", "bar"));
searcher.search(query, 1, Sort.INDEXORDER); // scores are not needed
List<ProfileResult> results = profiler.getQueryTree();
assertEquals(1, results.size());
Map<String, Long> breakdown = results.get(0).getTimeBreakdown();
assertThat(breakdown.get(ProfileBreakdown.TimingType.CREATE_WEIGHT.toString()).longValue(), greaterThan(0L));
assertThat(breakdown.get(ProfileBreakdown.TimingType.BUILD_SCORER.toString()).longValue(), greaterThan(0L));
assertThat(breakdown.get(ProfileBreakdown.TimingType.NEXT_DOC.toString()).longValue(), greaterThan(0L));
assertThat(breakdown.get(ProfileBreakdown.TimingType.ADVANCE.toString()).longValue(), equalTo(0L));
assertThat(breakdown.get(ProfileBreakdown.TimingType.SCORE.toString()).longValue(), equalTo(0L));
assertThat(breakdown.get(ProfileBreakdown.TimingType.MATCH.toString()).longValue(), equalTo(0L));
long rewriteTime = profiler.getRewriteTime();
assertThat(rewriteTime, greaterThan(0L));
}
public void testUseIndexStats() throws IOException {
Profiler profiler = new Profiler();
searcher.setProfiler(profiler);
Query query = new TermQuery(new Term("foo", "bar"));
searcher.count(query); // will use index stats
List<ProfileResult> results = profiler.getQueryTree();
assertEquals(0, results.size());
long rewriteTime = profiler.getRewriteTime();
assertThat(rewriteTime, greaterThan(0L));
}
public void testApproximations() throws IOException {
Profiler profiler = new Profiler();
Engine.Searcher engineSearcher = new Engine.Searcher("test", new IndexSearcher(reader));
// disable query caching since we want to test approximations, which won't
// be exposed on a cached entry
ContextIndexSearcher searcher = new ContextIndexSearcher(engineSearcher, null, MAYBE_CACHE_POLICY);
searcher.setProfiler(profiler);
Query query = new RandomApproximationQuery(new TermQuery(new Term("foo", "bar")), random());
searcher.count(query);
List<ProfileResult> results = profiler.getQueryTree();
assertEquals(1, results.size());
Map<String, Long> breakdown = results.get(0).getTimeBreakdown();
assertThat(breakdown.get(ProfileBreakdown.TimingType.CREATE_WEIGHT.toString()).longValue(), greaterThan(0L));
assertThat(breakdown.get(ProfileBreakdown.TimingType.BUILD_SCORER.toString()).longValue(), greaterThan(0L));
assertThat(breakdown.get(ProfileBreakdown.TimingType.NEXT_DOC.toString()).longValue(), greaterThan(0L));
assertThat(breakdown.get(ProfileBreakdown.TimingType.ADVANCE.toString()).longValue(), equalTo(0L));
assertThat(breakdown.get(ProfileBreakdown.TimingType.SCORE.toString()).longValue(), equalTo(0L));
assertThat(breakdown.get(ProfileBreakdown.TimingType.MATCH.toString()).longValue(), greaterThan(0L));
long rewriteTime = profiler.getRewriteTime();
assertThat(rewriteTime, greaterThan(0L));
}
public void testCollector() throws IOException {
TotalHitCountCollector collector = new TotalHitCountCollector();
ProfileCollector profileCollector = new ProfileCollector(collector);
assertEquals(0, profileCollector.getTime());
final LeafCollector leafCollector = profileCollector.getLeafCollector(reader.leaves().get(0));
assertThat(profileCollector.getTime(), greaterThan(0L));
long time = profileCollector.getTime();
leafCollector.setScorer(Lucene.illegalScorer("dummy scorer"));
assertThat(profileCollector.getTime(), greaterThan(time));
time = profileCollector.getTime();
leafCollector.collect(0);
assertThat(profileCollector.getTime(), greaterThan(time));
}
}

View File

@ -0,0 +1,596 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.search.profile;
import org.elasticsearch.action.search.*;
import org.elasticsearch.search.SearchHit;
import org.apache.lucene.util.English;
import org.elasticsearch.action.index.IndexRequestBuilder;
import org.elasticsearch.index.query.*;
import org.elasticsearch.search.sort.SortOrder;
import org.elasticsearch.test.ESIntegTestCase;
import java.util.Arrays;
import java.util.List;
import java.util.Map;
import static org.elasticsearch.search.profile.RandomQueryGenerator.randomQueryBuilder;
import static org.elasticsearch.test.hamcrest.DoubleMatcher.nearlyEqual;
import static org.hamcrest.Matchers.*;
public class QueryProfilerIT extends ESIntegTestCase {
/**
* This test simply checks to make sure nothing crashes. Test indexes 100-150 documents,
* constructs 20-100 random queries and tries to profile them
*/
public void testProfileQuery() throws Exception {
createIndex("test");
ensureGreen();
int numDocs = randomIntBetween(100, 150);
IndexRequestBuilder[] docs = new IndexRequestBuilder[numDocs];
for (int i = 0; i < numDocs; i++) {
docs[i] = client().prepareIndex("test", "type1", String.valueOf(i)).setSource(
"field1", English.intToEnglish(i),
"field2", i
);
}
List<String> stringFields = Arrays.asList("field1");
List<String> numericFields = Arrays.asList("field2");
indexRandom(true, docs);
refresh();
int iters = between(20, 100);
for (int i = 0; i < iters; i++) {
QueryBuilder q = randomQueryBuilder(stringFields, numericFields, numDocs, 3);
logger.info(q.toString());
SearchResponse resp = client().prepareSearch()
.setQuery(q)
.setProfile(true)
.setSearchType(SearchType.QUERY_THEN_FETCH)
.execute().actionGet();
assertNotNull("Profile response element should not be null", resp.getProfileResults());
for (Map.Entry<String, List<ProfileShardResult>> shard : resp.getProfileResults().entrySet()) {
for (ProfileShardResult searchProfiles : shard.getValue()) {
for (ProfileResult result : searchProfiles.getQueryResults()) {
assertNotNull(result.getQueryName());
assertNotNull(result.getLuceneDescription());
assertThat(result.getTime(), greaterThan(0L));
}
CollectorResult result = searchProfiles.getCollectorResult();
assertThat(result.getName(), not(isEmptyOrNullString()));
assertThat(result.getTime(), greaterThan(0L));
}
}
}
}
/**
* This test generates 1-10 random queries and executes a profiled and non-profiled
* search for each query. It then does some basic sanity checking of score and hits
* to make sure the profiling doesn't interfere with the hits being returned
*/
public void testProfileMatchesRegular() throws Exception {
createIndex("test");
ensureGreen();
int numDocs = randomIntBetween(100, 150);
IndexRequestBuilder[] docs = new IndexRequestBuilder[numDocs];
for (int i = 0; i < numDocs; i++) {
docs[i] = client().prepareIndex("test", "type1", String.valueOf(i)).setSource(
"field1", English.intToEnglish(i),
"field2", i
);
}
List<String> stringFields = Arrays.asList("field1");
List<String> numericFields = Arrays.asList("field2");
indexRandom(true, docs);
refresh();
int iters = between(1, 10);
for (int i = 0; i < iters; i++) {
QueryBuilder q = randomQueryBuilder(stringFields, numericFields, numDocs, 3);
logger.info(q.toString());
SearchRequestBuilder vanilla = client().prepareSearch("test")
.setQuery(q)
.setProfile(false)
.addSort("_score", SortOrder.DESC)
.addSort("_uid", SortOrder.ASC)
.setPreference("_primary")
.setSearchType(SearchType.QUERY_THEN_FETCH);
SearchRequestBuilder profile = client().prepareSearch("test")
.setQuery(q)
.setProfile(true)
.addSort("_score", SortOrder.DESC)
.addSort("_uid", SortOrder.ASC)
.setPreference("_primary")
.setSearchType(SearchType.QUERY_THEN_FETCH);
MultiSearchResponse.Item[] responses = client().prepareMultiSearch()
.add(vanilla)
.add(profile)
.execute().actionGet().getResponses();
SearchResponse vanillaResponse = responses[0].getResponse();
SearchResponse profileResponse = responses[1].getResponse();
float vanillaMaxScore = vanillaResponse.getHits().getMaxScore();
float profileMaxScore = profileResponse.getHits().getMaxScore();
if (Float.isNaN(vanillaMaxScore)) {
assertTrue("Vanilla maxScore is NaN but Profile is not [" + profileMaxScore + "]",
Float.isNaN(profileMaxScore));
} else {
assertTrue("Profile maxScore of [" + profileMaxScore + "] is not close to Vanilla maxScore [" + vanillaMaxScore + "]",
nearlyEqual(vanillaMaxScore, profileMaxScore, 0.001));
}
assertThat("Profile totalHits of [" + profileResponse.getHits().totalHits() + "] is not close to Vanilla totalHits [" + vanillaResponse.getHits().totalHits() + "]",
vanillaResponse.getHits().getTotalHits(), equalTo(profileResponse.getHits().getTotalHits()));
SearchHit[] vanillaHits = vanillaResponse.getHits().getHits();
SearchHit[] profileHits = profileResponse.getHits().getHits();
for (int j = 0; j < vanillaHits.length; j++) {
assertThat("Profile hit #" + j + " has a different ID from Vanilla",
vanillaHits[j].getId(), equalTo(profileHits[j].getId()));
}
}
}
/**
* This test verifies that the output is reasonable for a simple, non-nested query
*/
public void testSimpleMatch() throws Exception {
createIndex("test");
int numDocs = randomIntBetween(100, 150);
IndexRequestBuilder[] docs = new IndexRequestBuilder[numDocs];
for (int i = 0; i < numDocs; i++) {
docs[i] = client().prepareIndex("test", "type1", String.valueOf(i)).setSource(
"field1", English.intToEnglish(i),
"field2", i
);
}
indexRandom(true, docs);
ensureGreen();
QueryBuilder q = QueryBuilders.matchQuery("field1", "one");
SearchResponse resp = client().prepareSearch()
.setQuery(q)
.setProfile(true)
.setSearchType(SearchType.QUERY_THEN_FETCH)
.execute().actionGet();
Map<String, List<ProfileShardResult>> p = resp.getProfileResults();
assertNotNull(p);
for (Map.Entry<String, List<ProfileShardResult>> shardResult : resp.getProfileResults().entrySet()) {
for (ProfileShardResult searchProfiles : shardResult.getValue()) {
for (ProfileResult result : searchProfiles.getQueryResults()) {
assertEquals(result.getQueryName(), "TermQuery");
assertEquals(result.getLuceneDescription(), "field1:one");
assertThat(result.getTime(), greaterThan(0L));
assertNotNull(result.getTimeBreakdown());
}
CollectorResult result = searchProfiles.getCollectorResult();
assertThat(result.getName(), not(isEmptyOrNullString()));
assertThat(result.getTime(), greaterThan(0L));
}
}
}
/**
* This test verifies that the output is reasonable for a nested query
*/
public void testBool() throws Exception {
createIndex("test");
ensureGreen();
int numDocs = randomIntBetween(100, 150);
IndexRequestBuilder[] docs = new IndexRequestBuilder[numDocs];
for (int i = 0; i < numDocs; i++) {
docs[i] = client().prepareIndex("test", "type1", String.valueOf(i)).setSource(
"field1", English.intToEnglish(i),
"field2", i
);
}
indexRandom(true, docs);
QueryBuilder q = QueryBuilders.boolQuery().must(QueryBuilders.matchQuery("field1", "one")).must(QueryBuilders.matchQuery("field1", "two"));
SearchResponse resp = client().prepareSearch()
.setQuery(q)
.setProfile(true)
.setSearchType(SearchType.QUERY_THEN_FETCH)
.execute().actionGet();
Map<String, List<ProfileShardResult>> p = resp.getProfileResults();
assertNotNull(p);
for (Map.Entry<String, List<ProfileShardResult>> shardResult : resp.getProfileResults().entrySet()) {
for (ProfileShardResult searchProfiles : shardResult.getValue()) {
for (ProfileResult result : searchProfiles.getQueryResults()) {
assertEquals(result.getQueryName(), "BooleanQuery");
assertEquals(result.getLuceneDescription(), "+field1:one +field1:two");
assertThat(result.getTime(), greaterThan(0L));
assertNotNull(result.getTimeBreakdown());
assertEquals(result.getProfiledChildren().size(), 2);
// Check the children
List<ProfileResult> children = result.getProfiledChildren();
assertEquals(children.size(), 2);
ProfileResult childProfile = children.get(0);
assertEquals(childProfile.getQueryName(), "TermQuery");
assertEquals(childProfile.getLuceneDescription(), "field1:one");
assertThat(childProfile.getTime(), greaterThan(0L));
assertNotNull(childProfile.getTimeBreakdown());
assertEquals(childProfile.getProfiledChildren().size(), 0);
childProfile = children.get(1);
assertEquals(childProfile.getQueryName(), "TermQuery");
assertEquals(childProfile.getLuceneDescription(), "field1:two");
assertThat(childProfile.getTime(), greaterThan(0L));
assertNotNull(childProfile.getTimeBreakdown());
}
CollectorResult result = searchProfiles.getCollectorResult();
assertThat(result.getName(), not(isEmptyOrNullString()));
assertThat(result.getTime(), greaterThan(0L));
}
}
}
/**
* Tests a boolean query with no children clauses
*/
public void testEmptyBool() throws Exception {
createIndex("test");
ensureGreen();
int numDocs = randomIntBetween(100, 150);
IndexRequestBuilder[] docs = new IndexRequestBuilder[numDocs];
for (int i = 0; i < numDocs; i++) {
docs[i] = client().prepareIndex("test", "type1", String.valueOf(i)).setSource(
"field1", English.intToEnglish(i),
"field2", i
);
}
indexRandom(true, docs);
refresh();
QueryBuilder q = QueryBuilders.boolQuery();
logger.info(q.toString());
SearchResponse resp = client().prepareSearch()
.setQuery(q)
.setProfile(true)
.setSearchType(SearchType.QUERY_THEN_FETCH)
.execute().actionGet();
assertNotNull("Profile response element should not be null", resp.getProfileResults());
for (Map.Entry<String, List<ProfileShardResult>> shardResult : resp.getProfileResults().entrySet()) {
for (ProfileShardResult searchProfiles : shardResult.getValue()) {
for (ProfileResult result : searchProfiles.getQueryResults()) {
assertNotNull(result.getQueryName());
assertNotNull(result.getLuceneDescription());
assertThat(result.getTime(), greaterThan(0L));
assertNotNull(result.getTimeBreakdown());
}
CollectorResult result = searchProfiles.getCollectorResult();
assertThat(result.getName(), not(isEmptyOrNullString()));
assertThat(result.getTime(), greaterThan(0L));
}
}
}
/**
* Tests a series of three nested boolean queries with a single "leaf" match query.
* The rewrite process will "collapse" this down to a single bool, so this tests to make sure
* nothing catastrophic happens during that fairly substantial rewrite
*/
public void testCollapsingBool() throws Exception {
createIndex("test");
ensureGreen();
int numDocs = randomIntBetween(100, 150);
IndexRequestBuilder[] docs = new IndexRequestBuilder[numDocs];
for (int i = 0; i < numDocs; i++) {
docs[i] = client().prepareIndex("test", "type1", String.valueOf(i)).setSource(
"field1", English.intToEnglish(i),
"field2", i
);
}
indexRandom(true, docs);
refresh();
QueryBuilder q = QueryBuilders.boolQuery().must(QueryBuilders.boolQuery().must(QueryBuilders.boolQuery().must(QueryBuilders.matchQuery("field1", "one"))));
logger.info(q.toString());
SearchResponse resp = client().prepareSearch()
.setQuery(q)
.setProfile(true)
.setSearchType(SearchType.QUERY_THEN_FETCH)
.execute().actionGet();
assertNotNull("Profile response element should not be null", resp.getProfileResults());
for (Map.Entry<String, List<ProfileShardResult>> shardResult : resp.getProfileResults().entrySet()) {
for (ProfileShardResult searchProfiles : shardResult.getValue()) {
for (ProfileResult result : searchProfiles.getQueryResults()) {
assertNotNull(result.getQueryName());
assertNotNull(result.getLuceneDescription());
assertThat(result.getTime(), greaterThan(0L));
assertNotNull(result.getTimeBreakdown());
}
CollectorResult result = searchProfiles.getCollectorResult();
assertThat(result.getName(), not(isEmptyOrNullString()));
assertThat(result.getTime(), greaterThan(0L));
}
}
}
public void testBoosting() throws Exception {
createIndex("test");
ensureGreen();
int numDocs = randomIntBetween(100, 150);
IndexRequestBuilder[] docs = new IndexRequestBuilder[numDocs];
for (int i = 0; i < numDocs; i++) {
docs[i] = client().prepareIndex("test", "type1", String.valueOf(i)).setSource(
"field1", English.intToEnglish(i),
"field2", i
);
}
indexRandom(true, docs);
refresh();
QueryBuilder q = QueryBuilders.boostingQuery(QueryBuilders.matchQuery("field1", "one"), QueryBuilders.matchQuery("field1", "two"))
.boost(randomFloat())
.negativeBoost(randomFloat());
logger.info(q.toString());
SearchResponse resp = client().prepareSearch()
.setQuery(q)
.setProfile(true)
.setSearchType(SearchType.QUERY_THEN_FETCH)
.execute().actionGet();
assertNotNull("Profile response element should not be null", resp.getProfileResults());
for (Map.Entry<String, List<ProfileShardResult>> shardResult : resp.getProfileResults().entrySet()) {
for (ProfileShardResult searchProfiles : shardResult.getValue()) {
for (ProfileResult result : searchProfiles.getQueryResults()) {
assertNotNull(result.getQueryName());
assertNotNull(result.getLuceneDescription());
assertThat(result.getTime(), greaterThan(0L));
assertNotNull(result.getTimeBreakdown());
}
CollectorResult result = searchProfiles.getCollectorResult();
assertThat(result.getName(), not(isEmptyOrNullString()));
assertThat(result.getTime(), greaterThan(0L));
}
}
}
public void testDisMaxRange() throws Exception {
createIndex("test");
ensureGreen();
int numDocs = randomIntBetween(100, 150);
IndexRequestBuilder[] docs = new IndexRequestBuilder[numDocs];
for (int i = 0; i < numDocs; i++) {
docs[i] = client().prepareIndex("test", "type1", String.valueOf(i)).setSource(
"field1", English.intToEnglish(i),
"field2", i
);
}
indexRandom(true, docs);
refresh();
QueryBuilder q = QueryBuilders.disMaxQuery()
.boost(0.33703882f)
.add(QueryBuilders.rangeQuery("field2").from(null).to(73).includeLower(true).includeUpper(true));
logger.info(q.toString());
SearchResponse resp = client().prepareSearch()
.setQuery(q)
.setProfile(true)
.setSearchType(SearchType.QUERY_THEN_FETCH)
.execute().actionGet();
assertNotNull("Profile response element should not be null", resp.getProfileResults());
for (Map.Entry<String, List<ProfileShardResult>> shardResult : resp.getProfileResults().entrySet()) {
for (ProfileShardResult searchProfiles : shardResult.getValue()) {
for (ProfileResult result : searchProfiles.getQueryResults()) {
assertNotNull(result.getQueryName());
assertNotNull(result.getLuceneDescription());
assertThat(result.getTime(), greaterThan(0L));
assertNotNull(result.getTimeBreakdown());
}
CollectorResult result = searchProfiles.getCollectorResult();
assertThat(result.getName(), not(isEmptyOrNullString()));
assertThat(result.getTime(), greaterThan(0L));
}
}
}
public void testRange() throws Exception {
createIndex("test");
ensureGreen();
int numDocs = randomIntBetween(100, 150);
IndexRequestBuilder[] docs = new IndexRequestBuilder[numDocs];
for (int i = 0; i < numDocs; i++) {
docs[i] = client().prepareIndex("test", "type1", String.valueOf(i)).setSource(
"field1", English.intToEnglish(i),
"field2", i
);
}
indexRandom(true, docs);
refresh();
QueryBuilder q = QueryBuilders.rangeQuery("field2").from(0).to(5);
logger.info(q.toString());
SearchResponse resp = client().prepareSearch()
.setQuery(q)
.setProfile(true)
.setSearchType(SearchType.QUERY_THEN_FETCH)
.execute().actionGet();
assertNotNull("Profile response element should not be null", resp.getProfileResults());
for (Map.Entry<String, List<ProfileShardResult>> shardResult : resp.getProfileResults().entrySet()) {
for (ProfileShardResult searchProfiles : shardResult.getValue()) {
for (ProfileResult result : searchProfiles.getQueryResults()) {
assertNotNull(result.getQueryName());
assertNotNull(result.getLuceneDescription());
assertThat(result.getTime(), greaterThan(0L));
assertNotNull(result.getTimeBreakdown());
}
CollectorResult result = searchProfiles.getCollectorResult();
assertThat(result.getName(), not(isEmptyOrNullString()));
assertThat(result.getTime(), greaterThan(0L));
}
}
}
public void testPhrase() throws Exception {
createIndex("test");
ensureGreen();
int numDocs = randomIntBetween(100, 150);
IndexRequestBuilder[] docs = new IndexRequestBuilder[numDocs];
for (int i = 0; i < numDocs; i++) {
docs[i] = client().prepareIndex("test", "type1", String.valueOf(i)).setSource(
"field1", English.intToEnglish(i) + " " + English.intToEnglish(i+1),
"field2", i
);
}
indexRandom(true, docs);
refresh();
QueryBuilder q = QueryBuilders.matchPhraseQuery("field1", "one two");
logger.info(q.toString());
SearchResponse resp = client().prepareSearch()
.setQuery(q)
.setIndices("test")
.setTypes("type1")
.setProfile(true)
.setSearchType(SearchType.QUERY_THEN_FETCH)
.execute().actionGet();
if (resp.getShardFailures().length > 0) {
for (ShardSearchFailure f : resp.getShardFailures()) {
logger.error(f.toString());
}
fail();
}
assertNotNull("Profile response element should not be null", resp.getProfileResults());
for (Map.Entry<String, List<ProfileShardResult>> shardResult : resp.getProfileResults().entrySet()) {
for (ProfileShardResult searchProfiles : shardResult.getValue()) {
for (ProfileResult result : searchProfiles.getQueryResults()) {
assertNotNull(result.getQueryName());
assertNotNull(result.getLuceneDescription());
assertThat(result.getTime(), greaterThan(0L));
assertNotNull(result.getTimeBreakdown());
}
CollectorResult result = searchProfiles.getCollectorResult();
assertThat(result.getName(), not(isEmptyOrNullString()));
assertThat(result.getTime(), greaterThan(0L));
}
}
}
/**
* This test makes sure no profile results are returned when profiling is disabled
*/
public void testNoProfile() throws Exception {
createIndex("test");
ensureGreen();
int numDocs = randomIntBetween(100, 150);
IndexRequestBuilder[] docs = new IndexRequestBuilder[numDocs];
for (int i = 0; i < numDocs; i++) {
docs[i] = client().prepareIndex("test", "type1", String.valueOf(i)).setSource(
"field1", English.intToEnglish(i),
"field2", i
);
}
indexRandom(true, docs);
refresh();
QueryBuilder q = QueryBuilders.rangeQuery("field2").from(0).to(5);
logger.info(q.toString());
SearchResponse resp = client().prepareSearch().setQuery(q).setProfile(false).execute().actionGet();
assertThat("Profile response element should be an empty map", resp.getProfileResults().size(), equalTo(0));
}
}

View File

@ -0,0 +1,266 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.search.profile;
import org.apache.lucene.util.English;
import org.elasticsearch.common.unit.Fuzziness;
import org.elasticsearch.index.query.*;
import java.util.ArrayList;
import java.util.List;
import static com.carrotsearch.randomizedtesting.RandomizedTest.*;
import static org.junit.Assert.assertTrue;
public class RandomQueryGenerator {
public static QueryBuilder randomQueryBuilder(List<String> stringFields, List<String> numericFields, int numDocs, int depth) {
assertTrue("Must supply at least one string field", stringFields.size() > 0);
assertTrue("Must supply at least one numeric field", numericFields.size() > 0);
// If depth is exhausted, or 50% of the time return a terminal
// Helps limit ridiculously large compound queries
if (depth == 0 || randomBoolean()) {
return randomTerminalQuery(stringFields, numericFields, numDocs);
}
switch (randomIntBetween(0,5)) {
case 0:
return randomTerminalQuery(stringFields, numericFields, numDocs);
case 1:
return QueryBuilders.boolQuery().must(randomQueryBuilder(stringFields, numericFields, numDocs, depth -1))
.filter(randomQueryBuilder(stringFields, numericFields, numDocs, depth -1));
case 2:
return randomBoolQuery(stringFields, numericFields, numDocs, depth);
case 3:
// disabled for now because of https://issues.apache.org/jira/browse/LUCENE-6781
//return randomBoostingQuery(stringFields, numericFields, numDocs, depth);
case 4:
return randomConstantScoreQuery(stringFields, numericFields, numDocs, depth);
case 5:
return randomDisMaxQuery(stringFields, numericFields, numDocs, depth);
default:
return randomTerminalQuery(stringFields, numericFields, numDocs);
}
}
private static QueryBuilder randomTerminalQuery(List<String> stringFields, List<String> numericFields, int numDocs) {
switch (randomIntBetween(0,6)) {
case 0:
return randomTermQuery(stringFields, numDocs);
case 1:
return randomTermsQuery(stringFields, numDocs);
case 2:
return randomRangeQuery(numericFields, numDocs);
case 3:
return QueryBuilders.matchAllQuery();
case 4:
return randomCommonTermsQuery(stringFields, numDocs);
case 5:
return randomFuzzyQuery(stringFields);
case 6:
return randomIDsQuery();
default:
return randomTermQuery(stringFields, numDocs);
}
}
private static String randomQueryString(int max) {
StringBuilder qsBuilder = new StringBuilder();
for (int i = 0; i < max; i++) {
qsBuilder.append(English.intToEnglish(randomInt(max)));
qsBuilder.append(" ");
}
return qsBuilder.toString().trim();
}
private static String randomField(List<String> fields) {
return fields.get(randomInt(fields.size() - 1));
}
private static QueryBuilder randomTermQuery(List<String> fields, int numDocs) {
return QueryBuilders.termQuery(randomField(fields), randomQueryString(1));
}
private static QueryBuilder randomTermsQuery(List<String> fields, int numDocs) {
int numTerms = randomInt(numDocs);
ArrayList<String> terms = new ArrayList<>(numTerms);
for (int i = 0; i < numTerms; i++) {
terms.add(randomQueryString(1));
}
return QueryBuilders.termsQuery(randomField(fields), terms);
}
private static QueryBuilder randomRangeQuery(List<String> fields, int numDocs) {
QueryBuilder q = QueryBuilders.rangeQuery(randomField(fields));
if (randomBoolean()) {
((RangeQueryBuilder)q).from(randomIntBetween(0, numDocs / 2 - 1));
}
if (randomBoolean()) {
((RangeQueryBuilder)q).to(randomIntBetween(numDocs / 2, numDocs));
}
return q;
}
private static QueryBuilder randomBoolQuery(List<String> stringFields, List<String> numericFields, int numDocs, int depth) {
QueryBuilder q = QueryBuilders.boolQuery();
int numClause = randomIntBetween(0,5);
for (int i = 0; i < numClause; i++) {
((BoolQueryBuilder)q).must(randomQueryBuilder(stringFields, numericFields,numDocs, depth -1));
}
numClause = randomIntBetween(0,5);
for (int i = 0; i < numClause; i++) {
((BoolQueryBuilder)q).should(randomQueryBuilder(stringFields, numericFields,numDocs, depth -1));
}
numClause = randomIntBetween(0,5);
for (int i = 0; i < numClause; i++) {
((BoolQueryBuilder)q).mustNot(randomQueryBuilder(stringFields, numericFields, numDocs, depth -1));
}
return q;
}
private static QueryBuilder randomBoostingQuery(List<String> stringFields, List<String> numericFields, int numDocs, int depth) {
return QueryBuilders.boostingQuery(
randomQueryBuilder(stringFields, numericFields, numDocs, depth - 1),
randomQueryBuilder(stringFields, numericFields, numDocs, depth - 1))
.boost(randomFloat())
.negativeBoost(randomFloat());
}
private static QueryBuilder randomConstantScoreQuery(List<String> stringFields, List<String> numericFields, int numDocs, int depth) {
return QueryBuilders.constantScoreQuery(randomQueryBuilder(stringFields, numericFields, numDocs, depth - 1));
}
private static QueryBuilder randomCommonTermsQuery(List<String> fields, int numDocs) {
int numTerms = randomInt(numDocs);
QueryBuilder q = QueryBuilders.commonTermsQuery(randomField(fields), randomQueryString(numTerms));
if (randomBoolean()) {
((CommonTermsQueryBuilder)q).boost(randomFloat());
}
if (randomBoolean()) {
((CommonTermsQueryBuilder)q).cutoffFrequency(randomFloat());
}
if (randomBoolean()) {
((CommonTermsQueryBuilder)q).highFreqMinimumShouldMatch(Integer.toString(randomInt(numTerms)))
.highFreqOperator(randomBoolean() ? Operator.AND : Operator.OR);
}
if (randomBoolean()) {
((CommonTermsQueryBuilder)q).lowFreqMinimumShouldMatch(Integer.toString(randomInt(numTerms)))
.lowFreqOperator(randomBoolean() ? Operator.AND : Operator.OR);
}
return q;
}
private static QueryBuilder randomFuzzyQuery(List<String> fields) {
QueryBuilder q = QueryBuilders.fuzzyQuery(randomField(fields), randomQueryString(1));
if (randomBoolean()) {
((FuzzyQueryBuilder)q).boost(randomFloat());
}
if (randomBoolean()) {
switch (randomIntBetween(0, 4)) {
case 0:
((FuzzyQueryBuilder)q).fuzziness(Fuzziness.AUTO);
break;
case 1:
((FuzzyQueryBuilder)q).fuzziness(Fuzziness.ONE);
break;
case 2:
((FuzzyQueryBuilder)q).fuzziness(Fuzziness.TWO);
break;
case 3:
((FuzzyQueryBuilder)q).fuzziness(Fuzziness.ZERO);
break;
case 4:
((FuzzyQueryBuilder)q).fuzziness(Fuzziness.fromEdits(randomIntBetween(0,2)));
break;
default:
((FuzzyQueryBuilder)q).fuzziness(Fuzziness.AUTO);
break;
}
}
if (randomBoolean()) {
((FuzzyQueryBuilder)q).maxExpansions(Math.abs(randomInt()));
}
if (randomBoolean()) {
((FuzzyQueryBuilder)q).prefixLength(Math.abs(randomInt()));
}
if (randomBoolean()) {
((FuzzyQueryBuilder)q).transpositions(randomBoolean());
}
return q;
}
private static QueryBuilder randomDisMaxQuery(List<String> stringFields, List<String> numericFields, int numDocs, int depth) {
QueryBuilder q = QueryBuilders.disMaxQuery();
int numClauses = randomIntBetween(1, 10);
for (int i = 0; i < numClauses; i++) {
((DisMaxQueryBuilder)q).add(randomQueryBuilder(stringFields, numericFields, numDocs, depth - 1));
}
if (randomBoolean()) {
((DisMaxQueryBuilder)q).boost(randomFloat());
}
if (randomBoolean()) {
((DisMaxQueryBuilder)q).tieBreaker(randomFloat());
}
return q;
}
private static QueryBuilder randomIDsQuery() {
QueryBuilder q = QueryBuilders.idsQuery();
int numIDs = randomInt(100);
for (int i = 0; i < numIDs; i++) {
((IdsQueryBuilder)q).addIds(String.valueOf(randomInt()));
}
if (randomBoolean()) {
((IdsQueryBuilder)q).boost(randomFloat());
}
return q;
}
}

View File

@ -0,0 +1,45 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.test.hamcrest;
public class DoubleMatcher {
/**
* Better floating point comparisons courtesy of https://github.com/brazzy/floating-point-gui.de
*
* Snippet adapted to use doubles instead of floats
*/
public static boolean nearlyEqual(double a, double b, double epsilon) {
final double absA = Math.abs(a);
final double absB = Math.abs(b);
final double diff = Math.abs(a - b);
if (a == b) { // shortcut, handles infinities
return true;
} else if (a == 0 || b == 0 || diff < Double.MIN_NORMAL) {
// a or b is zero or both are extremely close to it
// relative error is less meaningful here
return diff < (epsilon * Double.MIN_NORMAL);
} else { // use relative error
return diff / Math.min((absA + absB), Double.MAX_VALUE) < epsilon;
}
}
}

View File

@ -95,6 +95,8 @@ include::search/validate.asciidoc[]
include::search/explain.asciidoc[]
include::search/profile.asciidoc[]
include::search/percolate.asciidoc[]
include::search/field-stats.asciidoc[]

View File

@ -0,0 +1,601 @@
[[search-profile]]
== Profile API
coming[2.2.0]
experimental[]
The Profile API provides detailed timing information about the execution of individual components
in a query. It gives the user insight into how queries are executed at a low level so that
the user can understand why certain queries are slow, and take steps to improve their slow queries.
The output from the Profile API is *very* verbose, especially for complicated queries executed across
many shards. Pretty-printing the response is recommended to help understand the output
[NOTE]
---------------------
The details provided by the Profile API directly expose Lucene class names and concepts, which means
that complete interpretation of the results require fairly advanced knowledge of Lucene. This
page attempts to give a crash-course in how Lucene executes queries so that you can use the Profile API to successfully
diagnose and debug queries, but it is only an overview. For complete understanding, please refer
to Lucene's documentation and, in places, the code.
With that said, a complete understanding is often not required to fix a slow query. It is usually
sufficient to see that a particular component of a query is slow, and not necessarily understand why
the `advance` phase of that query is the cause, for example.
---------------------
[float]
=== Usage
Any `_search` request can be profiled by adding a top-level `profile` parameter:
[source,js]
--------------------------------------------------
curl -XGET 'localhost:9200/_search' -d '{
"profile": true,<1>
"query" : {
"match" : { "message" : "search test" }
}
}
--------------------------------------------------
<1> Setting the top-level `profile` parameter to `true` will enable profiling
for the search
This will yield the following result:
[source,js]
--------------------------------------------------
{
"took": 25,
"timed_out": false,
"_shards": {
"total": 1,
"successful": 1,
"failed": 0
},
"hits": {
"total": 1,
"max_score": 1,
"hits": [ ... ] <1>
},
"profile": {
"shards": [
{
"id": "[htuC6YnSSSmKFq5UBt0YMA][test][0]",
"searches": [
{
"query": [
{
"query_type": "BooleanQuery",
"lucene": "message:search message:test",
"time": "15.52889800ms",
"breakdown": {
"score": 0,
"next_doc": 24495,
"match": 0,
"create_weight": 8488388,
"build_scorer": 7016015,
"advance": 0
},
"children": [
{
"query_type": "TermQuery",
"lucene": "message:search",
"time": "4.938855000ms",
"breakdown": {
"score": 0,
"next_doc": 18332,
"match": 0,
"create_weight": 2945570,
"build_scorer": 1974953,
"advance": 0
}
},
{
"query_type": "TermQuery",
"lucene": "message:test",
"time": "0.5016660000ms",
"breakdown": {
"score": 0,
"next_doc": 0,
"match": 0,
"create_weight": 170534,
"build_scorer": 331132,
"advance": 0
}
}
]
}
],
"rewrite_time": 185002,
"collector": [
{
"name": "SimpleTopScoreDocCollector",
"reason": "search_top_hits",
"time": "2.206529000ms"
}
]
}
]
}
]
}
}
--------------------------------------------------
<1> Search results are returned, but were omitted here for brevity
Even for a simple query, the response is relatively complicated. Let's break it down piece-by-piece before moving
to more complex examples.
First, the overall structure of the profile response is as follows:
[source,js]
--------------------------------------------------
{
"profile": {
"shards": [
{
"id": "[htuC6YnSSSmKFq5UBt0YMA][test][0]", <1>
"searches": [
{
"query": [...], <2>
"rewrite_time": 185002, <3>
"collector": [...] <4>
}
]
}
]
}
}
--------------------------------------------------
<1> A profile is returned for each shard that participated in the response, and is identified
by a unique ID
<2> Each profile contains a section which holds details about the query execution
<3> Each profile has a single time representing the cumulative rewrite time
<4> Each profile also contains a section about the Lucene Collectors which run the search
Because a search request may be executed against one or more shards in an index, and a search may cover
one or more indices, the top level element in the profile response is an array of `shard` objects.
Each shard object lists it's `id` which uniquely identifies the shard. The ID's format is
`[nodeID][indexName][shardID]`.
The profile itself may consist of one or more "searches", where a search is a query executed against the underlying
Lucene index. Most Search Requests submitted by the user will only execute a single `search` against the Lucene index.
But occasionally multiple searches will be executed, such as including a global aggregation (which needs to execute
a secondary "match_all" query for the global context).
Inside each `search` object there will be two arrays of profiled information:
a `query` array and a `collector` array. In the future, more sections may be added, such as `suggest`, `highlight`,
`aggregations`, etc
There will also be a `rewrite` metric showing the total time spent rewriting the query (in nanoseconds).
=== `query` Section
The `query` section contains detailed timing of the query tree executed by Lucene on a particular shard.
The overall structure of this query tree will resemble your original Elasticsearch query, but may be slightly
(or sometimes very) different. It will also use similar but not always identical naming. Using our previous
`term` query example, let's analyze the `query` section:
[source,js]
--------------------------------------------------
"query": [
{
"query_type": "BooleanQuery",
"lucene": "message:search message:test",
"time": "15.52889800ms",
"breakdown": {...},
"children": [
{
"query_type": "TermQuery",
"lucene": "message:search",
"time": "4.938855000ms",
"breakdown": {...}
},
{
"query_type": "TermQuery",
"lucene": "message:test",
"time": "0.5016660000ms",
"breakdown": {...}
}
]
}
]
--------------------------------------------------
<1> The breakdown timings are omitted for simplicity
Based on the profile structure, we can see that our `match` query was rewritten by Lucene into a BooleanQuery with two
clauses (both holding a TermQuery). The `"query_type"` field displays the Lucene class name, and often aligns with
the equivalent name in Elasticsearch. The `"lucene"` field displays the Lucene explanation text for the query, and
is made available to help differentiating between parts of your query (e.g. both `"message:search"` and `"message:test"`
are TermQuery's and would appear identical otherwise.
The `"time"` field shows that this query took ~15ms for the entire BooleanQuery to execute. The recorded time is inclusive
of all children.
The `"breakdown"` field will give detailed stats about how the time was spent, we'll look at
that in a moment. Finally, the `"children"` array lists any sub-queries that may be present. Because we searched for two
values ("search test"), our BooleanQuery holds two children TermQueries. They have identical information (query_type, time,
breakdown, etc). Children are allowed to have their own children.
==== Timing Breakdown
The `breakdown` component lists detailed timing statistics about low-level Lucene execution:
[source,js]
--------------------------------------------------
"breakdown": {
"score": 0,
"next_doc": 24495,
"match": 0,
"create_weight": 8488388,
"build_scorer": 7016015,
"advance": 0
}
--------------------------------------------------
Timings are listed in wall-clock nanoseconds and are not normalized at all. All caveats about the overall
`time` apply here. The intention of the breakdown is to give you a feel for A) what machinery in Lucene is
actually eating time, and B) the magnitude of differences in times between the various components. Like the overall time,
the breakdown is inclusive of all children times.
The meaning of the stats are as follows:
[float]
=== All parameters:
[horizontal]
`create_weight`::
A Query in Lucene must be capable of reuse across multiple IndexSearchers (think of it as the engine that
executes a search against a specific Lucene Index). This puts Lucene in a tricky spot, since many queries
need to accumulate temporary state/statistics associated with the index it is being used against, but the
Query contract mandates that it must be immutable.
To get around this, Lucene asks each query to generate a Weight object which acts as a temporary context
object to hold state associated with this particular (IndexSearcher, Query) tuple. The `weight` metric
shows how long this process takes
`build_scorer`::
This parameter shows how long it takes to build a Scorer for the query. A Scorer is the mechanism that
iterates over matching documents generates a score per-document (e.g. how well does "foo" match the document?).
Note, this records the time required to generate the Scorer object, not actuall score the documents. Some
queries have faster or slower initialization of the Scorer, depending on optimizations, complexity, etc.
This may also showing timing associated with caching, if enabled and/or applicable for the query
`next_doc`::
The Lucene method `next_doc` returns Doc ID of the next document matching the query. This statistic shows
the time it takes to determine which document is the next match, a process that varies considerably depending
on the nature of the query. Next_doc is a specialized form of advance() which is more convenient for many
queries in Lucene. It is equivalent to advance(docId() + 1)
`advance`::
`advance` is the "lower level" version of next_doc: it serves the same purpose of finding the next matching
doc, but requires the calling query to perform extra tasks such as identifying and moving past skips, etc.
However, not all queries can use next_doc, so `advance` is also timed for those queries.
Conjunctions (e.g. `must` clauses in a boolean) are typical consumers of `advance`
`matches`::
Some queries, such as phrase queries, match documents using a "Two Phase" process. First, the document is
"approximately" matched, and if it matches approximately, it is checked a second time with a more rigorous
(and expensive) process. The second phase verification is what the `matches` statistic measures.
For example, a phrase query first checks a document approximately by ensuring all terms in the phrase are
present in the doc. If all the terms are present, it then executes the second phase verification to ensure
the terms are in-order to form the phrase, which is relatively more expensive than just checking for presence
of the terms.
Because this two-phase process is only used by a handful of queries, the `metric` statistic will often be zero
`score`::
This records the time taken to score a particular document via it's Scorer
=== `collectors` Section
The Collectors portion of the response shows high-level execution details. Lucene works by defining a "Collector"
which is responsible for coordinating the traversal, scoring and collection of matching documents. Collectors
are also how a single query can record aggregation results, execute unscoped "global" queries, execute post-query
filters, etc.
Looking at the previous example:
[source,js]
--------------------------------------------------
"collector": [
{
"name": "SimpleTopScoreDocCollector",
"reason": "search_top_hits",
"time": "2.206529000ms"
}
]
--------------------------------------------------
We see a single collector named `SimpleTopScoreDocCollector`. This is the default "scoring and sorting" Collector
used by Elasticsearch. The `"reason"` field attempts to give an plain english description of the class name. The
`"time` is similar to the time in the Query tree: a wall-clock time inclusive of all children. Similarly, `children` lists
all sub-collectors.
It should be noted that Collector times are **independent** from the Query times. They are calculated, combined
and normalized independently! Due to the nature of Lucene's execution, it is impossible to "merge" the times
from the Collectors into the Query section, so they are displayed in separate portions.
For reference, the various collector reason's are:
[horizontal]
`search_sorted`::
A collector that scores and sorts documents. This is the most common collector and will be seen in most
simple searches
`search_count`::
A collector that only counts the number of documents that match the query, but does not fetch the source.
This is seen when `size: 0` or `search_type=count` is specified
`search_terminate_after_count`::
A collector that terminates search execution after `n` matching documents have been found. This is seen
when the `terminate_after_count` query parameter has been specified
`search_min_score`::
A collector that only returns matching documents that have a score greater than `n`. This is seen when
the top-level paramenter `min_score` has been specified.
`search_multi`::
A collector that wraps several other collectors. This is seen when combinations of search, aggregations,
global aggs and post_filters are combined in a single search.
`search_timeout`::
A collector that halts execution after a specified period of time. This is seen when a `timeout` top-level
parameter has been specified.
`aggregation`::
A collector that Elasticsearch uses to run aggregations against the query scope. A single `aggregation`
collector is used to collect documents for *all* aggregations, so you will see a list of aggregations
in the name rather.
`global_aggregation`::
A collector that executes an aggregation against the global query scope, rather than the specified query.
Because the global scope is necessarily different from the executed query, it must execute it's own
match_all query (which you will see added to the Query section) to collect your entire dataset
=== `rewrite` Section
All queries in Lucene undergo a "rewriting" process. A query (and its sub-queries) may be rewritten one or
more times, and the process continues until the query stops changing. This process allows Lucene to perform
optimizations, such as removing redundant clauses, replacing one query for a more efficient execution path,
etc. For example a Boolean -> Boolean -> TermQuery can be rewritten to a TermQuery, because all the Booleans
are unnecessary in this case.
The rewriting process is complex and difficult to display, since queries can change drastically. Rather than
showing the intermediate results, the total rewrite time is simply displayed as a value (in nanoseconds). This
value is cumulative and contains the total time for all queries being rewritten.
=== A more complex example
To demonstrate a slightly more complex query and the associated results, we can profile the following query:
[source,js]
--------------------------------------------------
GET /test/_search
{
"profile": true,
"query": {
"term": {
"message": {
"value": "search"
}
}
},
"aggs": {
"non_global_term": {
"terms": {
"field": "agg"
},
"aggs": {
"second_term": {
"terms": {
"field": "sub_agg"
}
}
}
},
"another_agg": {
"cardinality": {
"field": "aggB"
}
},
"global_agg": {
"global": {},
"aggs": {
"my_agg2": {
"terms": {
"field": "globalAgg"
}
}
}
}
},
"post_filter": {
"term": {
"my_field": "foo"
}
}
}
--------------------------------------------------
This example has:
- A query
- A scoped aggregation
- A global aggregation
- A post_filter
And the response:
[source,js]
--------------------------------------------------
{
"profile": {
"shards": [
{
"id": "[P6-vulHtQRWuD4YnubWb7A][test][0]",
"searches": [
{
"query": [
{
"query_type": "TermQuery",
"lucene": "my_field:foo",
"time": "0.4094560000ms",
"breakdown": {
"score": 0,
"next_doc": 0,
"match": 0,
"create_weight": 31584,
"build_scorer": 377872,
"advance": 0
}
},
{
"query_type": "TermQuery",
"lucene": "message:search",
"time": "0.3037020000ms",
"breakdown": {
"score": 0,
"next_doc": 5936,
"match": 0,
"create_weight": 185215,
"build_scorer": 112551,
"advance": 0
}
}
],
"rewrite_time": 7208,
"collector": [
{
"name": "MultiCollector",
"reason": "search_multi",
"time": "1.378943000ms",
"children": [
{
"name": "FilteredCollector",
"reason": "search_post_filter",
"time": "0.4036590000ms",
"children": [
{
"name": "SimpleTopScoreDocCollector",
"reason": "search_top_hits",
"time": "0.006391000000ms"
}
]
},
{
"name": "BucketCollector: [[non_global_term, another_agg]]",
"reason": "aggregation",
"time": "0.9546020000ms"
}
]
}
]
},
{
"query": [
{
"query_type": "MatchAllDocsQuery",
"lucene": "*:*",
"time": "0.04829300000ms",
"breakdown": {
"score": 0,
"next_doc": 3672,
"match": 0,
"create_weight": 6311,
"build_scorer": 38310,
"advance": 0
}
}
],
"rewrite_time": 1067,
"collector": [
{
"name": "GlobalAggregator: [global_agg]",
"reason": "aggregation_global",
"time": "0.1226310000ms"
}
]
}
]
}
]
}
}
--------------------------------------------------
As you can see, the output is significantly verbose from before. All the major portions of the query are
represented:
1. The first `TermQuery` (message:search) represents the main `term` query
2. The second `TermQuery` (my_field:foo) represents the `post_filter` query
3. There is a `MatchAllDocsQuery` (*:*) query which is being executed as a second, distinct search. This was
not part of the query specified by the user, but is auto-generated by the global aggregation to provide a global query scope
The Collector tree is fairly straightforward, showing how a single MultiCollector wraps a FilteredCollector
to execute the post_filter (and in turn wraps the normal scoring SimpleCollector), a BucketCollector to run
all scoped aggregations. In the MatchAll search, there is a single GlobalAggregator to run the global aggregation.
=== Performance Notes
Like any profiler, the Profile API introduce a non-negligible overhead to query execution. The act of instrumenting
low-level method calls such as `advance` and `next_doc` can be fairly expensive, since these methods are called
in tight loops. Therefore, profiling should not be enabled in production settings by default, and should not
be compared against non-profiled query times. Profiling is just a diagnostic tool.
There are also cases where special Lucene optimizations are disabled, since they are not amenable to profiling. This
could cause some queries to report larger relative times than their non-profiled counterparts, but in general should
not have a drastic effect compared to other components in the profiled query.
=== Limitations
- Profiling statistics are currently not available for suggestions, highlighting, `dfs_query_then_fetch`
- Detailed breakdown for aggregations is not currently available past the high-level overview provided
from the Collectors
- The Profiler is still highly experimental. The Profiler is instrumenting parts of Lucene that were
never designed to be exposed in this manner, and so all results should be viewed as a best effort to provide detailed
diagnostics. We hope to improve this over time. If you find obviously wrong numbers, strange query structures or
other bugs, please report them!
=== Understanding MultiTermQuery output
A special note needs to be made about the `MultiTermQuery` class of queries. This includes wildcards, regex and fuzzy
queries. These queries emit very verbose responses, and are not overly structured.
Essentially, these queries rewrite themselves on a per-segment basis. If you imagine the wildcard query `b*`, it technically
can match any token that begins with the letter "b". It would be impossible to enumerate all possible combinations,
so Lucene rewrites the query in context of the segment being evaluated. E.g. one segment may contain the tokens
`[bar, baz]`, so the query rewrites to a BooleanQuery combination of "bar" and "baz". Another segment may only have the
token `[bakery]`, so query rewrites to a single TermQuery for "bakery".
Due to this dynamic, per-segment rewriting, the clean tree structure becomes distorted and no longer follows a clean
"lineage" showing how one query rewrites into the next. At present time, all we can do is apologize, and suggest you
collapse the details for that query's children if it is too confusing. Luckily, all the timing statistics are correct,
just not the physical layout in the response, so it is sufficient to just analyze the top-level MultiTermQuery and
ignore it's children if you find the details too tricky to interpret.
Hopefully this will be fixed in future iterations, but it is a tricky problem to solve and still in-progress :)

View File

@ -35,7 +35,6 @@ import org.elasticsearch.common.util.BigArrays;
import org.elasticsearch.index.IndexService;
import org.elasticsearch.index.analysis.AnalysisService;
import org.elasticsearch.index.cache.bitset.BitsetFilterCache;
import org.elasticsearch.index.cache.query.QueryCache;
import org.elasticsearch.index.engine.Engine;
import org.elasticsearch.index.fielddata.IndexFieldDataService;
import org.elasticsearch.index.mapper.MappedFieldType;
@ -60,6 +59,8 @@ import org.elasticsearch.search.internal.ScrollContext;
import org.elasticsearch.search.internal.SearchContext;
import org.elasticsearch.search.internal.ShardSearchRequest;
import org.elasticsearch.search.lookup.SearchLookup;
import org.elasticsearch.search.profile.Profiler;
import org.elasticsearch.search.profile.Profilers;
import org.elasticsearch.search.query.QuerySearchResult;
import org.elasticsearch.search.rescore.RescoreSearchContext;
import org.elasticsearch.search.suggest.SuggestionSearchContext;
@ -293,7 +294,7 @@ public class TestSearchContext extends SearchContext {
}
public void setSearcher(Engine.Searcher searcher) {
this.searcher = new ContextIndexSearcher(this, searcher);
this.searcher = new ContextIndexSearcher(searcher, indexService.cache().query(), indexShard.getQueryCachingPolicy());
}
@Override
@ -660,8 +661,11 @@ public class TestSearchContext extends SearchContext {
public void copyContextAndHeadersFrom(HasContextAndHeaders other) {}
@Override
public Map<Class<?>, Collector> queryCollectors() {return queryCollectors;}
public Profilers getProfilers() {
return null; // no profiling
}
@Override
public QueryCache getQueryCache() { return indexService.cache().query();}
public Map<Class<?>, Collector> queryCollectors() {return queryCollectors;}
}