prabcs commented on issue #7099: broker metadata refresh failing URL: https://github.com/apache/druid/issues/7099#issuecomment-583053455 Notice that each log line shows an increasing amount of time for the metadata refresh. After a cap of 15000 segments, the broker leaves other segments for metadata refresh. I couldn't find any config that mentions 15000. Where could this be coming from ? ``` 2020-01-31T15:42:13,206 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 747 ms (1528 segments queried, 0 segments left). 2020-01-31T15:43:18,885 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 420 ms (2871 segments queried, 0 segments left). 2020-01-31T15:44:25,037 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 566 ms (4000 segments queried, 0 segments left). 2020-01-31T15:45:31,406 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 909 ms (5048 segments queried, 0 segments left). 2020-01-31T15:46:37,300 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 811 ms (5909 segments queried, 0 segments left). 2020-01-31T15:47:43,519 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 1,023 ms (6777 segments queried, 0 segments left). 2020-01-31T15:48:49,668 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 1,166 ms (7606 segments queried, 0 segments left). 2020-01-31T15:49:55,781 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 1,272 ms (8468 segments queried, 0 segments left). 2020-01-31T15:51:02,130 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 1,613 ms (9418 segments queried, 0 segments left). 2020-01-31T15:52:08,580 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 2,053 ms (10172 segments queried, 0 segments left). 2020-01-31T15:53:14,372 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 1,840 ms (11024 segments queried, 0 segments left). 2020-01-31T15:54:20,876 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 2,333 ms (12023 segments queried, 0 segments left). 2020-01-31T15:55:27,008 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 2,455 ms (13011 segments queried, 0 segments left). 2020-01-31T15:56:33,140 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 2,580 ms (13940 segments queried, 0 segments left). 2020-01-31T15:57:39,442 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 2,871 ms (14880 segments queried, 0 segments left). 2020-01-31T15:58:45,593 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 3,010 ms (15000 segments queried, 742 segments left). 2020-01-31T15:59:51,553 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 2,958 ms (15000 segments queried, 1603 segments left). 2020-01-31T16:00:57,607 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 3,002 ms (15000 segments queried, 2543 segments left). 2020-01-31T16:02:04,018 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 3,400 ms (15000 segments queried, 3395 segments left). 2020-01-31T16:03:09,920 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 3,288 ms (15000 segments queried, 4223 segments left). 2020-01-31T16:04:15,915 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 3,275 ms (15000 segments queried, 5058 segments left). 2020-01-31T16:05:21,977 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 3,325 ms (15000 segments queried, 5831 segments left). 2020-01-31T16:06:28,133 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 3,467 ms (15000 segments queried, 6591 segments left). 2020-01-31T16:07:34,268 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 3,589 ms (15000 segments queried, 7330 segments left). 2020-01-31T16:08:40,203 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 3,511 ms (15000 segments queried, 8071 segments left). 2020-01-31T16:09:46,269 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 3,565 ms (15000 segments queried, 8784 segments left). 2020-01-31T16:10:52,315 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 3,594 ms (15000 segments queried, 9488 segments left). 2020-01-31T16:12:13,769 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 19,037 ms (15000 segments queried, 10047 segments left). 2020-01-31T16:13:23,998 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 23,253 ms (15000 segments queried, 10534 segments left). 2020-01-31T16:14:28,414 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 21,655 ms (15000 segments queried, 10942 segments left). 2020-01-31T16:15:46,919 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 34,148 ms (15000 segments queried, 11286 segments left). 2020-01-31T16:17:20,032 INFO [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Refreshed metadata for dataSource[kafka_ingestion_datasource] in 61,247 ms (15000 segments queried, 11588 segments left). 2020-01-31T16:18:26,475 WARN [DruidSchema-Cache-0] org.apache.druid.sql.calcite.schema.DruidSchema - Metadata refresh failed, trying again soon. org.apache.druid.java.util.common.RE: Query[f3aea8ea-f54a-4d5e-a660-8b91c1a09c1a] url[http://10.128.0.171:8100/druid/v2/] failed with exception msg [Channel disconnected] at org.apache.druid.client.DirectDruidClient$1$2.hasMoreElements(DirectDruidClient.java:264) ~[druid-server-0.16.1-incubating.jar:0.16.1-incubating] at java.io.SequenceInputStream.nextStream(SequenceInputStream.java:109) ~[?:1.8.0_232] at java.io.SequenceInputStream.read(SequenceInputStream.java:211) ~[?:1.8.0_232] at com.fasterxml.jackson.dataformat.smile.SmileParser.loadMore(SmileParser.java:412) ~[jackson-dataformat-smile-2.6.7.jar:2.6.7] at com.fasterxml.jackson.dataformat.smile.SmileParser.nextToken(SmileParser.java:590) ~[jackson-dataformat-smile-2.6.7.jar:2.6.7] at org.apache.druid.client.JsonParserIterator.init(JsonParserIterator.java:138) ~[druid-server-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.client.JsonParserIterator.hasNext(JsonParserIterator.java:79) ~[druid-server-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.BaseSequence.makeYielder(BaseSequence.java:89) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.BaseSequence.toYielder(BaseSequence.java:69) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.MappedSequence.toYielder(MappedSequence.java:49) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.MergeSequence.lambda$toYielder$1(MergeSequence.java:64) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.MappingAccumulator.accumulate(MappingAccumulator.java:40) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.BaseSequence.accumulate(BaseSequence.java:44) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.MappedSequence.accumulate(MappedSequence.java:43) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.MergeSequence.toYielder(MergeSequence.java:61) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.LazySequence.toYielder(LazySequence.java:46) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.query.RetryQueryRunner$1.toYielder(RetryQueryRunner.java:97) ~[druid-processing-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.common.guava.CombiningSequence.toYielder(CombiningSequence.java:79) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.MappedSequence.toYielder(MappedSequence.java:49) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.MappedSequence.toYielder(MappedSequence.java:49) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.WrappingSequence$2.get(WrappingSequence.java:88) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.WrappingSequence$2.get(WrappingSequence.java:84) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.query.CPUTimeMetricQueryRunner$1.wrap(CPUTimeMetricQueryRunner.java:74) ~[druid-processing-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.WrappingSequence.toYielder(WrappingSequence.java:83) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.WrappingSequence$2.get(WrappingSequence.java:88) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.WrappingSequence$2.get(WrappingSequence.java:84) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.SequenceWrapper.wrap(SequenceWrapper.java:55) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.WrappingSequence.toYielder(WrappingSequence.java:83) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.Yielders.each(Yielders.java:32) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.sql.calcite.schema.DruidSchema.refreshSegmentsForDataSource(DruidSchema.java:521) ~[druid-sql-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.sql.calcite.schema.DruidSchema.refreshSegments(DruidSchema.java:477) ~[druid-sql-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.sql.calcite.schema.DruidSchema$2.run(DruidSchema.java:258) [druid-sql-0.16.1-incubating.jar:0.16.1-incubating] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_232] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_232] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_232] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_232] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_232] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_232] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_232] Suppressed: org.apache.druid.java.util.common.RE: Query[f3aea8ea-f54a-4d5e-a660-8b91c1a09c1a] url[http://10.128.0.171:8100/druid/v2/] failed with exception msg [Channel disconnected] at org.apache.druid.client.DirectDruidClient$1$2.hasMoreElements(DirectDruidClient.java:264) ~[druid-server-0.16.1-incubating.jar:0.16.1-incubating] at java.io.SequenceInputStream.nextStream(SequenceInputStream.java:109) ~[?:1.8.0_232] at java.io.SequenceInputStream.close(SequenceInputStream.java:232) ~[?:1.8.0_232] at com.fasterxml.jackson.dataformat.smile.SmileParser._closeInput(SmileParser.java:472) ~[jackson-dataformat-smile-2.6.7.jar:2.6.7] at com.fasterxml.jackson.core.base.ParserBase.close(ParserBase.java:385) ~[jackson-core-2.6.7.jar:2.6.7] at com.fasterxml.jackson.dataformat.smile.SmileParser.close(SmileParser.java:492) ~[jackson-dataformat-smile-2.6.7.jar:2.6.7] at org.apache.druid.client.JsonParserIterator.close(JsonParserIterator.java:168) ~[druid-server-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.CloseQuietly.close(CloseQuietly.java:39) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.client.DirectDruidClient$3.cleanup(DirectDruidClient.java:526) ~[druid-server-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.client.DirectDruidClient$3.cleanup(DirectDruidClient.java:508) ~[druid-server-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.BaseSequence.toYielder(BaseSequence.java:73) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.MappedSequence.toYielder(MappedSequence.java:49) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.MergeSequence.lambda$toYielder$1(MergeSequence.java:64) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.MappingAccumulator.accumulate(MappingAccumulator.java:40) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.BaseSequence.accumulate(BaseSequence.java:44) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.MappedSequence.accumulate(MappedSequence.java:43) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.MergeSequence.toYielder(MergeSequence.java:61) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.LazySequence.toYielder(LazySequence.java:46) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.query.RetryQueryRunner$1.toYielder(RetryQueryRunner.java:97) ~[druid-processing-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.common.guava.CombiningSequence.toYielder(CombiningSequence.java:79) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.MappedSequence.toYielder(MappedSequence.java:49) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.MappedSequence.toYielder(MappedSequence.java:49) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.WrappingSequence$2.get(WrappingSequence.java:88) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.WrappingSequence$2.get(WrappingSequence.java:84) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.query.CPUTimeMetricQueryRunner$1.wrap(CPUTimeMetricQueryRunner.java:74) ~[druid-processing-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.WrappingSequence.toYielder(WrappingSequence.java:83) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.WrappingSequence$2.get(WrappingSequence.java:88) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.WrappingSequence$2.get(WrappingSequence.java:84) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.SequenceWrapper.wrap(SequenceWrapper.java:55) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.WrappingSequence.toYielder(WrappingSequence.java:83) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.java.util.common.guava.Yielders.each(Yielders.java:32) ~[druid-core-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.sql.calcite.schema.DruidSchema.refreshSegmentsForDataSource(DruidSchema.java:521) ~[druid-sql-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.sql.calcite.schema.DruidSchema.refreshSegments(DruidSchema.java:477) ~[druid-sql-0.16.1-incubating.jar:0.16.1-incubating] at org.apache.druid.sql.calcite.schema.DruidSchema$2.run(DruidSchema.java:258) [druid-sql-0.16.1-incubating.jar:0.16.1-incubating] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_232] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_232] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_232] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_232] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_232] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_232] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_232] ``` This problem gets mitigated by lowering the number of `maxrowspersegment` but that ends up creating too many segments
---------------------------------------------------------------- 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. For queries about this service, please contact Infrastructure at: [email protected] With regards, Apache Git Services --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
