clintropolis opened a new pull request, #13420:
URL: https://github.com/apache/druid/pull/13420
### Description
Heh, I left out the call to `.emit` on the broker parallel merge pool
metrics so they just get reported into thin air. This PR fixes this so that
they now exist and look something like this (when wired up to a `QueryMetrics`
implementation that actually emits them, they are currently off by default):
```
2022-11-23T04:23:50,761 INFO [sql[e4429600-e50b-4fee-90f6-941c11204924]]
org.apache.druid.java.util.emitter.core.LoggingEmitter -
{"numComplexMetrics":"0","mergeParallelism":2,"type":"timeseries","version":"","duration":"PT9223372036854775.807S","feed":"metrics","metric":"query/merge/parallelism","hasFilters":"false","service":"druid/broker","host":"localhost:8082","context":{"defaultTimeout":300000,"finalize":false,"grandTotal":false,"maxScatterGatherBytes":9223372036854775807,"populateCache":false,"queryFailTime":1669177730685,"queryId":"e4429600-e50b-4fee-90f6-941c11204924","sqlOuterLimit":1001,"sqlQueryId":"e4429600-e50b-4fee-90f6-941c11204924","useCache":false},"limit":"2147483647","interval":["-146136543-09-08T08:23:32.096Z/146140482-04-24T15:36:27.903Z"],"id":"e4429600-e50b-4fee-90f6-941c11204924","numMetrics":"1","value":2,"dataSource":"wikipedia_rollup_test","timestamp":"2022-11-23T04:23:50.761Z"}
2022-11-23T04:23:50,761 INFO [sql[e4429600-e50b-4fee-90f6-941c11204924]]
org.apache.druid.java.util.emitter.core.LoggingEmitter -
{"numComplexMetrics":"0","mergeParallelism":2,"type":"timeseries","version":"","duration":"PT9223372036854775.807S","feed":"metrics","metric":"query/merge/sequences","hasFilters":"false","service":"druid/broker","host":"localhost:8082","context":{"defaultTimeout":300000,"finalize":false,"grandTotal":false,"maxScatterGatherBytes":9223372036854775807,"populateCache":false,"queryFailTime":1669177730685,"queryId":"e4429600-e50b-4fee-90f6-941c11204924","sqlOuterLimit":1001,"sqlQueryId":"e4429600-e50b-4fee-90f6-941c11204924","useCache":false},"limit":"2147483647","interval":["-146136543-09-08T08:23:32.096Z/146140482-04-24T15:36:27.903Z"],"id":"e4429600-e50b-4fee-90f6-941c11204924","numMetrics":"1","value":4,"dataSource":"wikipedia_rollup_test","timestamp":"2022-11-23T04:23:50.761Z"}
2022-11-23T04:23:50,761 INFO [sql[e4429600-e50b-4fee-90f6-941c11204924]]
org.apache.druid.java.util.emitter.core.LoggingEmitter -
{"numComplexMetrics":"0","mergeParallelism":2,"type":"timeseries","version":"","duration":"PT9223372036854775.807S","feed":"metrics","metric":"query/merge/rows/input","hasFilters":"false","service":"druid/broker","host":"localhost:8082","context":{"defaultTimeout":300000,"finalize":false,"grandTotal":false,"maxScatterGatherBytes":9223372036854775807,"populateCache":false,"queryFailTime":1669177730685,"queryId":"e4429600-e50b-4fee-90f6-941c11204924","sqlOuterLimit":1001,"sqlQueryId":"e4429600-e50b-4fee-90f6-941c11204924","useCache":false},"limit":"2147483647","interval":["-146136543-09-08T08:23:32.096Z/146140482-04-24T15:36:27.903Z"],"id":"e4429600-e50b-4fee-90f6-941c11204924","numMetrics":"1","value":4,"dataSource":"wikipedia_rollup_test","timestamp":"2022-11-23T04:23:50.761Z"}
2022-11-23T04:23:50,761 INFO [sql[e4429600-e50b-4fee-90f6-941c11204924]]
org.apache.druid.java.util.emitter.core.LoggingEmitter -
{"numComplexMetrics":"0","mergeParallelism":2,"type":"timeseries","version":"","duration":"PT9223372036854775.807S","feed":"metrics","metric":"query/merge/rows/output","hasFilters":"false","service":"druid/broker","host":"localhost:8082","context":{"defaultTimeout":300000,"finalize":false,"grandTotal":false,"maxScatterGatherBytes":9223372036854775807,"populateCache":false,"queryFailTime":1669177730685,"queryId":"e4429600-e50b-4fee-90f6-941c11204924","sqlOuterLimit":1001,"sqlQueryId":"e4429600-e50b-4fee-90f6-941c11204924","useCache":false},"limit":"2147483647","interval":["-146136543-09-08T08:23:32.096Z/146140482-04-24T15:36:27.903Z"],"id":"e4429600-e50b-4fee-90f6-941c11204924","numMetrics":"1","value":4,"dataSource":"wikipedia_rollup_test","timestamp":"2022-11-23T04:23:50.761Z"}
2022-11-23T04:23:50,761 INFO [sql[e4429600-e50b-4fee-90f6-941c11204924]]
org.apache.druid.java.util.emitter.core.LoggingEmitter -
{"numComplexMetrics":"0","mergeParallelism":2,"type":"timeseries","version":"","duration":"PT9223372036854775.807S","feed":"metrics","metric":"query/merge/tasks/count","hasFilters":"false","service":"druid/broker","host":"localhost:8082","context":{"defaultTimeout":300000,"finalize":false,"grandTotal":false,"maxScatterGatherBytes":9223372036854775807,"populateCache":false,"queryFailTime":1669177730685,"queryId":"e4429600-e50b-4fee-90f6-941c11204924","sqlOuterLimit":1001,"sqlQueryId":"e4429600-e50b-4fee-90f6-941c11204924","useCache":false},"limit":"2147483647","interval":["-146136543-09-08T08:23:32.096Z/146140482-04-24T15:36:27.903Z"],"id":"e4429600-e50b-4fee-90f6-941c11204924","numMetrics":"1","value":10,"dataSource":"wikipedia_rollup_test","timestamp":"2022-11-23T04:23:50.761Z"}
2022-11-23T04:23:50,761 INFO [sql[e4429600-e50b-4fee-90f6-941c11204924]]
org.apache.druid.java.util.emitter.core.LoggingEmitter -
{"numComplexMetrics":"0","mergeParallelism":2,"type":"timeseries","version":"","duration":"PT9223372036854775.807S","feed":"metrics","metric":"query/merge/cpu","hasFilters":"false","service":"druid/broker","host":"localhost:8082","context":{"defaultTimeout":300000,"finalize":false,"grandTotal":false,"maxScatterGatherBytes":9223372036854775807,"populateCache":false,"queryFailTime":1669177730685,"queryId":"e4429600-e50b-4fee-90f6-941c11204924","sqlOuterLimit":1001,"sqlQueryId":"e4429600-e50b-4fee-90f6-941c11204924","useCache":false},"limit":"2147483647","interval":["-146136543-09-08T08:23:32.096Z/146140482-04-24T15:36:27.903Z"],"id":"e4429600-e50b-4fee-90f6-941c11204924","numMetrics":"1","value":0,"dataSource":"wikipedia_rollup_test","timestamp":"2022-11-23T04:23:50.761Z"}
2022-11-23T04:23:50,761 INFO [sql[e4429600-e50b-4fee-90f6-941c11204924]]
org.apache.druid.java.util.emitter.core.LoggingEmitter -
{"numComplexMetrics":"0","mergeParallelism":2,"type":"timeseries","version":"","duration":"PT9223372036854775.807S","feed":"metrics","metric":"query/merge/time","hasFilters":"false","service":"druid/broker","host":"localhost:8082","context":{"defaultTimeout":300000,"finalize":false,"grandTotal":false,"maxScatterGatherBytes":9223372036854775807,"populateCache":false,"queryFailTime":1669177730685,"queryId":"e4429600-e50b-4fee-90f6-941c11204924","sqlOuterLimit":1001,"sqlQueryId":"e4429600-e50b-4fee-90f6-941c11204924","useCache":false},"limit":"2147483647","interval":["-146136543-09-08T08:23:32.096Z/146140482-04-24T15:36:27.903Z"],"id":"e4429600-e50b-4fee-90f6-941c11204924","numMetrics":"1","value":65,"dataSource":"wikipedia_rollup_test","timestamp":"2022-11-23T04:23:50.761Z"}
2022-11-23T04:23:50,761 INFO [sql[e4429600-e50b-4fee-90f6-941c11204924]]
org.apache.druid.java.util.emitter.core.LoggingEmitter -
{"numComplexMetrics":"0","mergeParallelism":2,"type":"timeseries","version":"","duration":"PT9223372036854775.807S","feed":"metrics","metric":"query/merge/partition/slowest","hasFilters":"false","service":"druid/broker","host":"localhost:8082","context":{"defaultTimeout":300000,"finalize":false,"grandTotal":false,"maxScatterGatherBytes":9223372036854775807,"populateCache":false,"queryFailTime":1669177730685,"queryId":"e4429600-e50b-4fee-90f6-941c11204924","sqlOuterLimit":1001,"sqlQueryId":"e4429600-e50b-4fee-90f6-941c11204924","useCache":false},"limit":"2147483647","interval":["-146136543-09-08T08:23:32.096Z/146140482-04-24T15:36:27.903Z"],"id":"e4429600-e50b-4fee-90f6-941c11204924","numMetrics":"1","value":63,"dataSource":"wikipedia_rollup_test","timestamp":"2022-11-23T04:23:50.761Z"}
2022-11-23T04:23:50,761 INFO [sql[e4429600-e50b-4fee-90f6-941c11204924]]
org.apache.druid.java.util.emitter.core.LoggingEmitter -
{"numComplexMetrics":"0","mergeParallelism":2,"type":"timeseries","version":"","duration":"PT9223372036854775.807S","feed":"metrics","metric":"query/merge/partition/fastest","hasFilters":"false","service":"druid/broker","host":"localhost:8082","context":{"defaultTimeout":300000,"finalize":false,"grandTotal":false,"maxScatterGatherBytes":9223372036854775807,"populateCache":false,"queryFailTime":1669177730685,"queryId":"e4429600-e50b-4fee-90f6-941c11204924","sqlOuterLimit":1001,"sqlQueryId":"e4429600-e50b-4fee-90f6-941c11204924","useCache":false},"limit":"2147483647","interval":["-146136543-09-08T08:23:32.096Z/146140482-04-24T15:36:27.903Z"],"id":"e4429600-e50b-4fee-90f6-941c11204924","numMetrics":"1","value":40,"dataSource":"wikipedia_rollup_test","timestamp":"2022-11-23T04:23:50.761Z"}
```
I've also added three new metrics, one for total 'wall' time of the sequence
from construction to being totally consume, and one each for the time spent
waiting for the fastest and slowest partitions to initialize (fetch the first
batch of results to begin work). The three of these should provide some
additional insight into how time was spent by the tasks on the pool to
accompany the existing set of metrics (which actually exist now).
#### Release note
* Fix an issue which cause broker parallel merge pool metrics to not be
emitted.
* Added new broker query metric for total parallel merge processing 'wall'
time
* Added new broker query metrics for parallel merge pool time spent waiting
for results of 'fastest' and 'slowest' partitions.
<!-- Check the items by putting "x" in the brackets for the done things. Not
all of these items apply to every PR. Remove the items which are not done or
not relevant to the PR. None of the items from the checklist below are strictly
necessary, but it would be very helpful if you at least self-review the PR. -->
This PR has:
- [ ] been self-reviewed.
- [ ] added documentation for new or modified features or behaviors.
- [ ] a release note entry in the PR description.
- [ ] added Javadocs for most classes and all non-trivial methods. Linked
related entities via Javadoc links.
- [ ] added comments explaining the "why" and the intent of the code
wherever would not be obvious for an unfamiliar reader.
- [ ] added unit tests or modified existing tests to cover new code paths,
ensuring the threshold for [code
coverage](https://github.com/apache/druid/blob/master/dev/code-review/code-coverage.md)
is met.
- [ ] been tested in a test Druid cluster.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
