{"action":"opened","issue":{"url":"https://api.github.com/repos/elastic/elasticsearch/issues/18693","repository_url":"https://api.github.com/repos/elastic/elasticsearch","labels_url":"https://api.github.com/repos/elastic/elasticsearch/issues/18693/labels{/name}","comments_url":"https://api.github.com/repos/elastic/elasticsearch/issues/18693/comments","events_url":"https://api.github.com/repos/elastic/elasticsearch/issues/18693/events","html_url":"https://github.com/elastic/elasticsearch/issues/18693","id":158020055,"number":18693,"title":"Why is lucene query execution time more than query's \"took\" value, according to Profile API?","user":{"login":"apanimesh061","id":3243029,"avatar_url":"https://avatars.githubusercontent.com/u/3243029?v=3","gravatar_id":"","url":"https://api.github.com/users/apanimesh061","html_url":"https://github.com/apanimesh061","followers_url":"https://api.github.com/users/apanimesh061/followers","following_url":"https://api.github.com/users/apanimesh061/following{/other_user}","gists_url":"https://api.github.com/users/apanimesh061/gists{/gist_id}","starred_url":"https://api.github.com/users/apanimesh061/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/apanimesh061/subscriptions","organizations_url":"https://api.github.com/users/apanimesh061/orgs","repos_url":"https://api.github.com/users/apanimesh061/repos","events_url":"https://api.github.com/users/apanimesh061/events{/privacy}","received_events_url":"https://api.github.com/users/apanimesh061/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":0,"created_at":"2016-06-01T22:20:25Z","updated_at":"2016-06-01T22:20:25Z","closed_at":null,"body":"```\r\n{\r\n  \"took\": 125241,\r\n  \"timed_out\": false,\r\n  \"_shards\": {\r\n    \"total\": 24,\r\n    \"successful\": 24,\r\n    \"failed\": 0\r\n  },\r\n  \"hits\": {\r\n    \"total\": 265076,\r\n    \"max_score\": 3,\r\n    \"hits\": [...]\r\n  },\r\n  \"profile\": {\r\n    \"shards\": [\r\n      {\r\n        \"id\": \"[klNxl8HWTyqF-f8BRBbiiA][traackr][0]\",\r\n        \"searches\": [\r\n          {\r\n            \"query\": [\r\n              {\r\n                \"query_type\": \"BooleanQuery\",\r\n                \"lucene\": \"...\",\r\n                \"time\": \"247695.9417ms\",\r\n.\r\n.\r\n.\r\n.\r\n            \"rewrite_time\": 505668,\r\n            \"collector\": [\r\n              {\r\n                \"name\": \"SimpleFieldCollector\",\r\n                \"reason\": \"search_top_hits\",\r\n                \"time\": \"110.2805510ms\"\r\n              }\r\n            ]\r\n          }\r\n        ]\r\n      }\r\n    ]\r\n  }\r\n}\r\n```\r\nThere is a query that was taking 3 seconds so I thought of profiling it using the `Profile API`.\r\nYou can see the result above,\r\n\r\nI cannot understand when the value of `took` is `125241 ms`, how come the top-level Lucene query and the rewrite time are greater than this value? Am I missing something here?\r\n\r\nES Version: 2.3.3\r\nJava: 1.8\r\n"}}
{"actor":{"display_login":"apanimesh061"}}