Apache Druid

Screenshot 2022-09-16 at 1.16.56 PM.png

*Overlord Logs:*
```2022-09-16T09:32:25,820 DEBUG [HttpClient-Netty-Worker-5] org.apache.druid.java.util.http.client.NettyHttpClient - [POST <http://192.168.28.87:8091/druid/worker/v1/task/index_kafka_networks_stage_72d587d4679eb62_jmloppea/shutdown>] Got response: 500 Server Error
         vmop                    [threads: total initially_running wait_to_block]    [time: spin block sync cleanup vmop] page_trap_count
27212.057: RevokeBias                       [     159          0              0    ]      [     0     0     0     0     0    ]  0   
2022-09-16T09:32:25,820 INFO [TaskQueue-Manager] org.apache.druid.indexing.overlord.RemoteTaskRunner - Sent shutdown message to worker: 192.168.28.87:8091, status 500 Server Error, response: &lt;html&gt;
&lt;head&gt;
&lt;meta http-equiv="Content-Type" content="text/html;charset=utf-8"/&gt;
&lt;title&gt;Error 500 org.apache.druid.java.util.common.IAE: No userMap is available for authenticator with prefix: [MyBasicMetadataAuthenticator]&lt;/title&gt;
&lt;/head&gt;
&lt;body&gt;&lt;h2&gt;HTTP ERROR 500 org.apache.druid.java.util.common.IAE: No userMap is available for authenticator with prefix: [MyBasicMetadataAuthenticator]&lt;/h2&gt;
&lt;table&gt;
&lt;tr&gt;&lt;th&gt;URI:&lt;/th&gt;&lt;td&gt;/druid/worker/v1/task/index_kafka_networks_stage_72d587d4679eb62_jmloppea/shutdown&lt;/td&gt;&lt;/tr&gt;
&lt;tr&gt;&lt;th&gt;STATUS:&lt;/th&gt;&lt;td&gt;500&lt;/td&gt;&lt;/tr&gt;
&lt;tr&gt;&lt;th&gt;MESSAGE:&lt;/th&gt;&lt;td&gt;org.apache.druid.java.util.common.IAE: No userMap is available for authenticator with prefix: [MyBasicMetadataAuthenticator]&lt;/td&gt;&lt;/tr&gt;
&lt;tr&gt;&lt;th&gt;SERVLET:&lt;/th&gt;&lt;td&gt;org.eclipse.jetty.servlet.DefaultServlet-46ea78f0&lt;/td&gt;&lt;/tr&gt;
&lt;tr&gt;&lt;th&gt;CAUSED BY:&lt;/th&gt;&lt;td&gt;org.apache.druid.java.util.common.IAE: No userMap is available for authenticator with prefix: [MyBasicMetadataAuthenticator]&lt;/td&gt;&lt;/tr&gt;
&lt;/table&gt;
&lt;h3&gt;Caused by:&lt;/h3&gt;&lt;pre&gt;org.apache.druid.java.util.common.IAE: No userMap is available for authenticator with prefix: [MyBasicMetadataAuthenticator]
	at org.apache.druid.security.basic.authentication.validator.MetadataStoreCredentialsValidator.validateCredentials(MetadataStoreCredentialsValidator.java:64)
	at org.apache.druid.security.basic.authentication.BasicHTTPAuthenticator$BasicHTTPAuthenticationFilter.doFilter(BasicHTTPAuthenticator.java:200)
	at org.apache.druid.server.security.AuthenticationWrappingFilter.doFilter(AuthenticationWrappingFilter.java:59)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
	at org.apache.druid.server.security.SecuritySanityCheckFilter.doFilter(SecuritySanityCheckFilter.java:77)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:548)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1435)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1350)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:763)
	at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:59)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
	at org.eclipse.jetty.server.Server.handle(Server.java:516)
	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388)
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:383)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:882)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1036)
	at java.lang.Thread.run(Thread.java:748)
&lt;/pre&gt;

&lt;/body&gt;
&lt;/html&gt;

         vmop                    [threads: total initially_running wait_to_block]    [time: spin block sync cleanup vmop] page_trap_count
27212.057: RevokeBias                       [     159          0              0    ]      [     0     0     0     0     0    ]  0   
2022-09-16T09:32:25,821 ERROR [TaskQueue-Manager] org.apache.druid.indexing.overlord.RemoteTaskRunner - Shutdown failed for index_kafka_networks_stage_72d587d4679eb62_jmloppea! Are you sure the task was running?
         vmop                    [threads: total initially_running wait_to_block]    [time: spin block sync cleanup vmop] page_trap_count```

Middle Manager Logs:
```2022-09-16T09:21:36,325 DEBUG [main-SendThread(druid-zookeeper-1.druid-zookeeper-headless.druid.svc.cluster.local:2181)] org.apache.zookeeper.ClientCnxn - Got ping response for sessionid: 0x2009bc5e62d0008 after 0ms
2022-09-16T09:21:38,166 DEBUG [prometheus-http-1-2] com.sun.net.httpserver - GET /metrics HTTP/1.1 [200  OK] ()
2022-09-16T09:21:40,408 DEBUG [prometheus-http-1-3] com.sun.net.httpserver - GET /metrics HTTP/1.1 [200  OK] ()
2022-09-16T09:21:40,815 WARN [BasicAuthenticatorCacheManager-Exec--0] org.apache.druid.java.util.common.RetryUtils - Retrying (9 of 9) in 58,764ms.
org.apache.druid.java.util.common.IOE: No known server
	at org.apache.druid.discovery.DruidLeaderClient.getCurrentKnownLeader(DruidLeaderClient.java:267) ~[druid-server-0.23.0.jar:0.23.0]
	at org.apache.druid.discovery.DruidLeaderClient.makeRequest(DruidLeaderClient.java:122) ~[druid-server-0.23.0.jar:0.23.0]
	at org.apache.druid.security.basic.authentication.db.cache.CoordinatorPollingBasicAuthenticatorCacheManager.tryFetchUserMapFromCoordinator(CoordinatorPollingBasicAuthenticatorCacheManager.java:252) ~[?:?]
	at org.apache.druid.security.basic.authentication.db.cache.CoordinatorPollingBasicAuthenticatorCacheManager.lambda$fetchUserMapFromCoordinator$1(CoordinatorPollingBasicAuthenticatorCacheManager.java:192) ~[?:?]
	at org.apache.druid.java.util.common.RetryUtils.retry(RetryUtils.java:129) ~[druid-core-0.23.0.jar:0.23.0]
	at org.apache.druid.java.util.common.RetryUtils.retry(RetryUtils.java:81) ~[druid-core-0.23.0.jar:0.23.0]
	at org.apache.druid.java.util.common.RetryUtils.retry(RetryUtils.java:163) ~[druid-core-0.23.0.jar:0.23.0]
	at org.apache.druid.java.util.common.RetryUtils.retry(RetryUtils.java:153) ~[druid-core-0.23.0.jar:0.23.0]
	at org.apache.druid.security.basic.authentication.db.cache.CoordinatorPollingBasicAuthenticatorCacheManager.fetchUserMapFromCoordinator(CoordinatorPollingBasicAuthenticatorCacheManager.java:190) ~[?:?]
	at org.apache.druid.security.basic.authentication.db.cache.CoordinatorPollingBasicAuthenticatorCacheManager.lambda$start$0(CoordinatorPollingBasicAuthenticatorCacheManager.java:122) ~[?:?]
	at org.apache.druid.java.util.common.concurrent.ScheduledExecutors$1.call(ScheduledExecutors.java:55) [druid-core-0.23.0.jar:0.23.0]
	at org.apache.druid.java.util.common.concurrent.ScheduledExecutors$1.call(ScheduledExecutors.java:51) [druid-core-0.23.0.jar:0.23.0]
	at org.apache.druid.java.util.common.concurrent.ScheduledExecutors$2.run(ScheduledExecutors.java:97) [druid-core-0.23.0.jar:0.23.0]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_275]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_275]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_275]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_275]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_275]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_275]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
2022-09-16T09:21:43,456 DEBUG [MonitorScheduler-0] org.apache.druid.emitter.prometheus.PrometheusEmitter - Unmapped metric [jvm/cpu/user]```

*Historicals Logs:*
```2022-09-16T08:42:57,813 DEBUG [main-SendThread(druid-zookeeper-2.druid-zookeeper-headless.druid.svc.cluster.local:2181)] org.apache.zookeeper.ClientCnxn - Got ping response for sessionid: 0x303b27dcd460007 after 0ms
2022-09-16T08:43:01,090 WARN [BasicAuthenticatorCacheManager-Exec--0] org.apache.druid.java.util.common.RetryUtils - Retrying (9 of 9) in 66,809ms.
org.apache.druid.java.util.common.IOE: No known server
	at org.apache.druid.discovery.DruidLeaderClient.getCurrentKnownLeader(DruidLeaderClient.java:267) ~[druid-server-0.23.0.jar:0.23.0]
	at org.apache.druid.discovery.DruidLeaderClient.makeRequest(DruidLeaderClient.java:122) ~[druid-server-0.23.0.jar:0.23.0]
	at org.apache.druid.security.basic.authentication.db.cache.CoordinatorPollingBasicAuthenticatorCacheManager.tryFetchUserMapFromCoordinator(CoordinatorPollingBasicAuthenticatorCacheManager.java:252) ~[?:?]
	at org.apache.druid.security.basic.authentication.db.cache.CoordinatorPollingBasicAuthenticatorCacheManager.lambda$fetchUserMapFromCoordinator$1(CoordinatorPollingBasicAuthenticatorCacheManager.java:192) ~[?:?]
	at org.apache.druid.java.util.common.RetryUtils.retry(RetryUtils.java:129) ~[druid-core-0.23.0.jar:0.23.0]
	at org.apache.druid.java.util.common.RetryUtils.retry(RetryUtils.java:81) ~[druid-core-0.23.0.jar:0.23.0]
	at org.apache.druid.java.util.common.RetryUtils.retry(RetryUtils.java:163) ~[druid-core-0.23.0.jar:0.23.0]
	at org.apache.druid.java.util.common.RetryUtils.retry(RetryUtils.java:153) ~[druid-core-0.23.0.jar:0.23.0]
	at org.apache.druid.security.basic.authentication.db.cache.CoordinatorPollingBasicAuthenticatorCacheManager.fetchUserMapFromCoordinator(CoordinatorPollingBasicAuthenticatorCacheManager.java:190) ~[?:?]
	at org.apache.druid.security.basic.authentication.db.cache.CoordinatorPollingBasicAuthenticatorCacheManager.lambda$start$0(CoordinatorPollingBasicAuthenticatorCacheManager.java:122) ~[?:?]
	at org.apache.druid.java.util.common.concurrent.ScheduledExecutors$1.call(ScheduledExecutors.java:55) [druid-core-0.23.0.jar:0.23.0]
	at org.apache.druid.java.util.common.concurrent.ScheduledExecutors$1.call(ScheduledExecutors.java:51) [druid-core-0.23.0.jar:0.23.0]
	at org.apache.druid.java.util.common.concurrent.ScheduledExecutors$2.run(ScheduledExecutors.java:97) [druid-core-0.23.0.jar:0.23.0]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_275]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_275]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_275]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_275]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_275]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_275]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
2022-09-16T08:43:01,613 DEBUG [prometheus-http-1-5] com.sun.net.httpserver - GET /metrics HTTP/1.1 [200  OK] ()```

For how long was the Zookeeper down. Also were there any changes to the metadata store during the time?

It would have been down max for 2 minutes. No, there was no change in the metadata.

When ZK goes down, you may need to restart your Druid Coordinator/Overlord if they got stuck not being able to elect a leader

Setting these properties is also helpful, as it moves 3 important pieces of functionality from ZK -&gt; HTTP, which increases reliability when recovering from ZK unavailability

```druid.indexer.runner.type = httpRemote
druid.serverview.type = http
druid.coordinator.loadqueuepeon.type = http```

i am having issues trying to index from kafka.

the task finished ok but i the datasource it's not there.

qps_datasource.json

index_kafka_qps_297e3acb918a5a1_clcfaihm.report.json

index_kafka_qps_297e3acb918a5a1_clcfaihm_log.sh

It appears from the report that no records were processed

I don't believe the datasource would appear in such a case if it doesn't exist already

Yes u are right this log are from a period where there stream was empty let me get another task details

a.log

it's looks like a kafka issue . But i don't find an error on kafka server side

Could you please share the leader overlord logs around 15:10 to 15:20 so that we can learn more about the supervisor?

i incremented the pooltimeout and the expcetion it is not repetead any more.

they where lot of issue all together . oom , aws s3 misconfigurations (something related with acl enabled) and kafka far away/timeout.

That's quite the topic. Try reading this <https://druid.apache.org/docs/latest/operations/basic-cluster-tuning.html#middlemanager|article> and tune accordingly.
It might be the http threads but it also can be the processing threads in the historicals, low memory?

You can read the replies to this <https://apachedruidworkspace.slack.com/archives/C0309C9L90D/p1662099163931169?thread_ts=1662065365.614959&amp;cid=C0309C9L90D|comment> and it might help you

top three generic pieces of performance advice:

1) ensure your setup is configured well for your server. we have a bunch of pre-written configs at <https://druid.apache.org/docs/latest/operations/single-server.html> you can start from. the most important settings to get right from the start are `druid.processing.numThreads`, `druid.processing.buffer.sizeBytes`, and `-Xmx` in jvm.config

2) ensure you don't have too many small segments: overheads per-segment can be high in this case. you can use the web console or `sys.segments` table to see the average number of rows per segment. Generally we target a few million per segment. Lower is OK if you have a smaller amount of data. But you don't want tons of segments that are, like, 10000 rows each

3) you can use a flame graph <https://support.imply.io/hc/en-us/articles/360033747953-Profiling-Druid-queries-using-flame-graphs> to see what specific code is taking up your processing time. very useful tool!

The context of the question is that we are seeing historicals are holding on to the segments past their retention durations, causing the historical boxes to go out of space to load new segments

Our `Max segments to move` is set to 500, while `Balancer compute threads`  are 7.

it runs on its own once a minute: there isn't a way to force it, but that's pretty often 

i wonder if you're seeing a problem where the run takes a lot longer than normal? can happen with large numbers of segments; using cachingCost balancer and/or setting maxSegmentsInNodeLoadingQueue helps here

To add, any chance you are using tiering in historicals? It also might be worth increasing the replication throttle limit setting on the coordinator. See - <https://apachedruidworkspace.slack.com/archives/C0309C9L90D/p1656700175994759?thread_ts=1656633981.766599&amp;cid=C0309C9L90D>

This is relevant especially if you are seeing log messages like below in your coordinator log.
```<http://log.info|log.info>("Loading in progress, skipping drop until loading is complete");```

In my case I <https://apachedruidworkspace.slack.com/archives/C0309C9L90D/p1656706078753939?thread_ts=1656633981.766599&amp;cid=C0309C9L90D|bumped> up the limit from 10k.

thank you <@U030GL518NR>! Just go through the other conversation that you mentioned above. One concern is will increase `replicationThrottleLimit` affect the segment loading speed?

`replicationThrottleLimit` is basically controlling number of segments that can replicated in one round.

There is some weirdness in Druid where it doesn't execute the drop rule if replication is throttled.
Do you see lots of "skipping drop" log lines in coordinator log?

but the weird thing is we didnt see that datasource has segment loading or dropping in druid console

and we do using multiple tiers, the tier that we find the out of retention data not been removed has already been has 100% usage while checking the Sevice tab in the console

yeah, very similar symptoms. In our case the hot tier was running out of space since the coordinator was never able to issue drop requests to remove the data from the historicals.

Two things that we did that helped resolve the issue for us:
1. Increase `replicationThrottleLimit`
2. Run two or more coordinators and bounce coordinators in a staggered fashion using a cron script. 
I would try with 1 first and see if helps resolve your issue.

How many segments are there on your cluster?

yeah, i will try these options. i am not sure the exact number of segments, but i think it is more than 1m segments

`Loading in progress, skipping drop until loading is complete` could occur upon addition of a new tier which is underrpelicated as Samarth has said

Is there an issue with balancing or are tiers getting overreplicated? If it's the former, reducing maxSegmentsToMove temporarily could prevent further worsening of the tiers

<https://github.com/apache/druid/issues/12881> the first item describes how balancing generally leads to a "temporary" overreplication. If drops are being skipped your tiers might get overreplicated

Yep, our cluster has 300k+ segments with tiering and realtime ingestion enabled and the above setup has helped. 

We have run into cases where the coordinator was just busy trying to move data to cold tier and not handoff any segments from the peons for a long time. So we had to resort to bouncing the coordinators in a staggered fashion otherwise handoff would just timeout and the tasks would fail and retry ingestion. I. short, bad news. 

&gt; Is there an issue with balancing or are tiers getting overreplicated? If it's the former, reducing maxSegmentsToMove temporarily could prevent further worsening of the tiers
I meant the latter: overreplication on other tiers

Thank you for pointing to the github issue, <@U0319HD8HEC> . I am glad to see focus on improving/fixing various issues in Druid coordinator. 

if you are OK doing it with downtime, that works

if you have persistent vols on your MMs and don't want downtime, you can also update each one in-place

the tasks will be restored after MM restart

ah… I used ephemeral EBS for MM. So the moment the pod is deleted, the EBS is gone.

But thank you for confirming! I have 2 hours of downtime budget for each Druid upgrade, so yeah, downtime is not a big deal.

Do you have the `druid-kinesis-indexing-service` extension loaded everywhere?

we use kafka indexing service. it is loaded and unchanged from 0.23.0.

can you share full logs of your coordinator?

I also use kafka with 24 and have no problems. Make sure you have the extension loaded in the common config

```druid.extensions.loadList=[..."druid-kafka-indexing-service"...]```

druid-druid-coordinators-new.txt

<@U03V6S23FHN> We do have the kafka extensions loaded in common properties for all components.

Hmm I have a suspicion about what is going on here… <@U03DW1FMU4X> have you noticed if this resolved itself?

If my guess is right it should resolve after a background metadata store update completes

Suspicion: <https://github.com/apache/druid/issues/13132>

Coordinator's CompactSegments has
```        Map&lt;String, DataSourceCompactionConfig&gt; compactionConfigs = compactionConfigList
            .stream()
            .collect(Collectors.toMap(DataSourceCompactionConfig::getDataSource, Function.identity()));
        final List&lt;TaskStatusPlus&gt; compactionTasks = filterNonCompactionTasks(indexingServiceClient.getActiveTasks());```
indexingServiceClient.getActiveTasks() has not been changed as part of #12404

`filterNonCompactionTasks`  may think of tasks of an older version as compaction tasks
```  private static List&lt;TaskStatusPlus&gt; filterNonCompactionTasks(List&lt;TaskStatusPlus&gt; taskStatuses)
  {
    return taskStatuses
        .stream()
        .filter(status -&gt; {
          final String taskType = status.getType();
          // taskType can be null if middleManagers are running with an older version. Here, we consevatively regard
          // the tasks of the unknown taskType as the compactionTask. This is because it's important to not run
          // compactionTasks more than the configured limit at any time which might impact to the ingestion
          // performance.
          return taskType == null || COMPACTION_TASK_TYPE.equals(taskType);
        })
        .collect(Collectors.toList());
  }```

Yeah I was thinking that's what's going on; filterNonCompsctionTasks returns the older tasks (since type is null) and then they can't be deserialized 

Since the Coordinator deserializes them using ClientQueryTask which doesn't support kafka tasks

<@U03DW1FMU4X> Could you please share your overlord logs during this time as well?

Thanks folks for taking a look at this! It does seem to go away. I no longer see the error at least for the past few hours. Our overlord has warn log level and does not produce many logs. I will keep the thread posted if I see occurrences of this and will share the logs here.
Thanks folks for taking a look at this.

Screen Shot 2022-09-19 at 8.36.05 PM.png

There is this: <https://druid.apache.org/docs/latest/tutorials/tutorial-msq-extern.html>

Also the new quickstart for which I just made a video: <https://www.youtube.com/watch?v=PZpu8hOfRJw> (careful, it is still hot off the press)

Also I made a longer video for the stuff right before the 24.0.0 code freeze that 99% still applies <https://www.youtube.com/watch?v=xUzYuPfzARk>

(I will give $50 to the first person that sports a bug featured in that video that was fixed before the 24.0 release - sometimes I QA by making videos)

I got:
```Error: Unknown exception

org.apache.druid.rpc.HttpResponseException: Server error [400 Bad Request]; body: {"error":"Please make sure to load all the necessary extensions and jars with type 'query_controller' on 'druid/overlord' service. Could not resolve type id 'query_controller' as a subtype of `org.apache.druid.indexing.common.task.Task` known type ids = [archive, compact, index, index_hadoop, index_kafka, index_kinesis, index_parallel, index_realtime, index_realtime_appenderator, index_sub, kill, move, noop, partial_dimension_cardinality, partial_dimension_distribution, partial_index_generate, partial_index_generic_merge, partial_range_index_generate, restore, single_phase_sub_task]\n at [Source: (org.eclipse.jetty.server.HttpInputOverHTTP); line: 1, column: 9]"}

java.lang.RuntimeException```
I enabled the multi-stage-query extension already

are you sure it is loaded on your overlord? that error means it is not loaded

they are all packaged together in 1 docker image, but I can check

image.png

Finally saving the best for last: you can take a self guided tour by loading the demo queries

oh, if you are using docker make sure to edit the `environment` file, see <https://github.com/apache/druid/pull/13069>

Is `EXTERN` not able to read from S3? e.g.
```{"type":"s3","uris":["<s3://mybucket/multi-stage-query/kttm-v2-2019-08-25.json.gz>"]}```

I got `Request failed with status code 403`

default `admin` role should have full `EXTERNAL` access, yeah?

Are you connecting to a fresh database or an old db instance with druid data filled in ?

See the 3rd paragraph here: <https://druid.apache.org/docs/latest/multi-stage-query/index.html#load-the-extension>

I will try to repro it tomorrow. I have a hunch into what might be happening.

did you end up getting it to work? if it's an old instance w/ security enabled, you do need to manually add the EXTERNAL / EXTERNAL permission to the admin role

it is automatically added to new admin roles for fresh installs, but not for an upgrade of an existing install

Yup yup, I think that’s the problem. I haven’t had the time to try it yet, will try tomorrow.

`it is automatically added to new admin roles for fresh installs, but not for an upgrade of an existing install`
I was thinking of changing this part. Upgrades basically add/remove the new roles

```CoordinatorBasicAuthorizerMetadataStorageUpdater#initSuperUsersAndGroupMapping```
<@U0344FW86DD> wdyt ?

If we cannot do it for all, I was thinking we can make basic auth work seamlessly at-least.

yeah, we can't do it for all auth mechanisms, but it would be great to do it automatically for basic

I see resource.type = VIEW, what is that?

There is external write (by symmetry) but it does not do anything right now 

VIEW resources are for views created in Druid 

Screen Shot 2022-09-20 at 8.42.46 PM.png

The query bombed though…
```java.lang.RuntimeException: org.apache.druid.msq.indexing.error.MSQException: WorkerFailed: Worker task failed: [query-1986e125-4ca3-484f-853e-44971a8a0cca-worker0] (This task disappeared on the worker where it was assigned. See overlord logs for more details.)
	at org.apache.druid.common.guava.FutureUtils.getUnchecked(FutureUtils.java:78)
	at org.apache.druid.common.guava.FutureUtils.getUncheckedImmediately(FutureUtils.java:90)
	at org.apache.druid.msq.exec.ControllerImpl$RunQueryUntilDone.lambda$startTaskLauncher$1(ControllerImpl.java:1970)
	at org.apache.druid.msq.exec.ControllerImpl$RunQueryUntilDone.runKernelCommands(ControllerImpl.java:1944)
	at org.apache.druid.msq.exec.ControllerImpl$RunQueryUntilDone.run(ControllerImpl.java:1925)
	at org.apache.druid.msq.exec.ControllerImpl$RunQueryUntilDone.access$000(ControllerImpl.java:1877)
	at org.apache.druid.msq.exec.ControllerImpl.runTask(ControllerImpl.java:352)
	at org.apache.druid.msq.exec.ControllerImpl.run(ControllerImpl.java:296)
	at org.apache.druid.msq.indexing.MSQControllerTask.run(MSQControllerTask.java:192)
	at org.apache.druid.indexing.overlord.ThreadingTaskRunner$1.call(ThreadingTaskRunner.java:210)
	at org.apache.druid.indexing.overlord.ThreadingTaskRunner$1.call(ThreadingTaskRunner.java:152)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
	at java.base/java.lang.Thread.run(Thread.java:1589)
Caused by: org.apache.druid.msq.indexing.error.MSQException: WorkerFailed: Worker task failed: [query-1986e125-4ca3-484f-853e-44971a8a0cca-worker0] (This task disappeared on the worker where it was assigned. See overlord logs for more details.)```

So….… looks like MM is involved in querying now. Does that mean I need to have a separate MM pool just for MSQ?

It doesn't need to be separate necessarily but it does need to exist

We're using MMs since this iteration is focused on batch query and ingest (like `INSERT ... SELECT`). So tasks/MMs are a natural fit

I love the idea of using MM, in 1 of my largest cluster they are sitting idle after the big ingest window is finished. They need to earn their keeps :stuck_out_tongue_closed_eyes:

We currently do not have an `UNNEST`, so there is no direct way to explode the multi-value dimensions AFAIK.

One roundabout way I can think of is to use groupBy.
<https://druid.apache.org/docs/latest/querying/multi-value-dimensions.html#grouping>

You basically run a group by on the multi-value column and get the number of rows in the result.

```SELECT COUNT(*) FROM (
SELECT multi_value_column FROM your_datasource
GROUP BY 1
)```

Try increasing the query timeout in your context.

Query context reference: <https://druid.apache.org/docs/latest/querying/query-context.html#general-parameters>

4 minutes and running :smile:
it's a crazy expensive query, no? especially without any time limit?

Yeah, it definitely is expensive :sweat_smile: , especially if your datasource is big.
It explodes the multiple values from each row and then groups on those distinct values. As a test, let's see if it gives the desired results. But I wouldn't advise running it in a prod setup as your other queries might get starved for resources.

COUNT(DISTINCT) might just be good enough...

Oops, my bad! `DISTINCT` already does the explode for us :face_palm:

however, what DOES COUNT(DISTINCT) count?
It's far closer to the workaround than to COUNT(*)

just count distinct is around the same time

Yeah, that should be expected as count distinct is the real work in the query. The rest is just summation. But I guess 30s is okay, given you have 1M rows.

still not bad, given how much of a roundabout approach that was :stuck_out_tongue:

It was grouping on 48M unique values :joy:

yeah, guess my segment size optimizations finally paid off :smile:

How did you go about doing these optimizations?

Had to migrate data and put some brain grease into configuring the reindex task correctly. and I set up compaction

so new data is eventually also put into month-sized segments

interesting, a bigger number of rows per segment didn't work well enough?
how many MBs is each segment now?

good enough for our use case. queries are much much faster than before when we had multiple tiny segments per day due to bad configuration

still wondering where the discrepancy between workaround and COUNT(DISTINCT) is coming from...

oh, I thought you had even bigger segments earlier!
Yeah, multiple tiny segments is very bad. I think you can still go bigger.
You can try to push your segment size to 200k or 500k even, atleast as an experiment.

&gt;  still wondering where the discrepancy between workaround and COUNT(DISTINCT) is coming from...
Maybe `useApproximateCountDistinct` is set to true?

&gt; You can try to push your segment size to 200k or 500k even, atleast as an experiment.
Druid normally advises segment size of 2M to 5M rows, but given that row size seems big, you can experiment in incremental steps and try to push it to 1M.

It's a productive system, so no experiments :smile: I think everyone is happy with the much improved performance already. I was aiming at the 300-700MB segment size described in the docs

That's good to hear! Let us know if you run into any other issue.

I did not change it, so probably it's still default (true)

Made a PR for a clarification in the docs. Hope this is helpful.
<https://github.com/apache/druid/pull/13128>

Great, thanks! Will review it in some time.

just two things

1) enable the extension and
2) if it's an upgrade to a cluster w/ security enabled, add the EXTERNAL/EXTERNAL permission

both mentioned @ <https://druid.apache.org/docs/latest/multi-stage-query/index.html#load-the-extension>

This is why I love Druid, even thought there’s a ramp up cost learning 6 services, but after that it’s so easy for SRE folks.

```{
  "level": "ERROR",
  "thread": "HttpServerInventoryView-4",
  "message": "failed to get sync response from [<http://10.4.132.249:8091/_1663714827177>]. Return code [0], Reason: [null]",
  "exception": {
    "exception_class": "org.jboss.netty.channel.ChannelException",
    "exception_message": "Faulty channel in resource pool",
    "stacktrace": "org.jboss.netty.channel.ChannelException: Faulty channel in resource pool\n\tat org.apache.druid.java.util.http.client.NettyHttpClient.go(NettyHttpClient.java:131)\n\tat org.apache.druid.server.coordination.ChangeRequestHttpSyncer.sync(ChangeRequestHttpSyncer.java:218)\n\tat java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)\n\tat java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)\n\tat java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)\n\tat java.base/java.lang.Thread.run(Thread.java:829)\nCaused by: org.jboss.netty.channel.ConnectTimeoutException: connection timed out: /10.4.132.249:8091\n\tat org.jboss.netty.channel.socket.nio.NioClientBoss.processConnectTimeout(NioClientBoss.java:139)\n\tat org.jboss.netty.channel.socket.nio.NioClientBoss.process(NioClientBoss.java:83)\n\tat org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:337)\n\tat org.jboss.netty.channel.socket.nio.NioClientBoss.run(NioClientBoss.java:42)\n\tat org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)\n\tat org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)\n\t... 3 more\n"
  },
  "hostName": "storage--druid-coordinator-8454fd4cf5-zz94r"
}```

The stacktrace made more understandishable:
```org.jboss.netty.channel.ChannelException: Faulty channel in resource pool
  at org.apache.druid.java.util.http.client.NettyHttpClient.go(NettyHttpClient.java:131)
  at org.apache.druid.server.coordination.ChangeRequestHttpSyncer.sync(ChangeRequestHttpSyncer.java:218)
  at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
  at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
  at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
  at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
  at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
  at java.base/java.lang.Thread.run(Thread.java:829)
  Caused by: org.jboss.netty.channel.ConnectTimeoutException: connection timed out: /10.4.132.249:8091
  at org.jboss.netty.channel.socket.nio.NioClientBoss.processConnectTimeout(NioClientBoss.java:139)
  at org.jboss.netty.channel.socket.nio.NioClientBoss.process(NioClientBoss.java:83)
  at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:337)
  at org.jboss.netty.channel.socket.nio.NioClientBoss.run(NioClientBoss.java:42)
  at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
  at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)
  ... 3 more\n```

This leads me to believe that the coordinator is still attempting to communicate with the indexer.

I am curious if anyone else has seen an error like this.

It appears that once it gets into this state it will continue to retry indefinitely, and eventually the coordinator becomes bogged down and non-responsive

If the coordinator pod is deleted it whoever takes over as leader is usually fine, but eventually this occurs again

I would like to be able to specify the retry limit for errors such as these so that they don't build up over time and destabilize the coordinator.

Could this be the Java hostname resolution cache issue? My thoughts were:
• the log shows the IP address of the failed Indexer
• Is the Indexer in a statefulset? i.e getting the same hostname when it returns with a different IP?
• there have been other conversations where the host resolution caching in the JVM is the culprit, but I'm not sure if this is at play here.
The other thread for reference: <https://apachedruidworkspace.slack.com/archives/C0309C9L90D/p1657433748772419>

Added this info to <https://github.com/apache/druid/issues/12904>, where we're tracking production experiences w/ this extension

I'm wondering if, at the time this was logged, did 10.4.132.249 exist?

That would be consistent with the behavior you mentioned: restarting fixes it, but it gets back into the state over time

<@U030MNRGBNG> When you saw these bad IP addresses again, check the ZK and see if ZK still keep track of them. I assume you are putting in ip addresses in ZK, yes?

oh wait, never mind, you use Kubernetes, hm… so weird

I do have these errors when I use `http` for server inventory. We switched them back to `batch` and never got those errors.

&gt; I'm wondering if, at the time this was logged, did 10.4.132.249 exist?
No, that IP no longer existed.

&gt; • Is the Indexer in a statefulset? i.e getting the same hostname when it returns with a different IP?
We run everything as deployments, so each pod gets a new IP.

&gt; there have been other conversations where the host resolution caching in the JVM is the culprit, but I'm not sure if this is at play here.
This was one of my first ideas, that the JVM was using a stale IP.  I expected that there would be a limit on the number of retries before the coordinator flags the node as out of service and removes it from memory.

In general our service discovery stuff works the other way around: clients will keep trying to contact services as long as the service discovery says they're going to be there

In other words they don't "second-guess" the list they get from service discovery

This does sound like a service discovery issue

Like, something related to K8sDruidNodeDiscoveryProvider

I am not a k8s expert so I am not sure exactly how that class is supposed to work

But I am guessing it is returning some quite stale IPs in some cases

(For reference, the ZK-based version works through ephemeral znode watches: when a server goes away, it stops heartbeating with ZK, so its ephemeral znode is deleted. The CuratorDruidNodeDiscoveryProvider notices that and removes the server from the active list.)

I am going to dig deeper into the implementation and see if I can determine why the the coordinator still thinks these nodes exist.  The indexers un-announce themselves when they are shutting down so the coordinators _should_ know they are gone and can be pruned.

<@U0344FW86DD> Does `K8sDruidNodeDiscoveryProvider` still use `druid.host` for looking up the IP or hostname?

I am not sure, and I gotta step away for a bit so can't check right now

Thanks Cory, that would be awesome

For reference: the way things are _supposed_ to work is the DruidNodeDiscovery (from the K8sDruidNodeDiscoveryProvider, or any other discovery provider) is the final word on what the correct list of servers is for a given role. So the expectation in this case is once a server goes offline, the discovery impl will notice it somehow, and update its list. Then clients will stop trying to talk to it

I manually deleted an indexer pod and captured the following message in the coordinator:
```"thread":"org.apache.druid.k8s.discovery.K8sDruidNodeDiscoveryProvider$NodeRoleWatcherpeon","message":"Node[<http://10.4.131.88:8091>] of role[peon] went offline."```
So that confirms that the indexer un-announced, and that the coordinator received the message.

I found an NPE right after that
```java.lang.NullPointerException
at org.apache.druid.client.HttpServerInventoryView$2.toDruidServer(HttpServerInventoryView.java:179)
at org.apache.druid.client.HttpServerInventoryView$2.lambda$nodesRemoved$1(HttpServerInventoryView.java:161)
at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)\n\tat java.base/java.util.Collections$UnmodifiableCollection.forEach(Collections.java:1085)
at org.apache.druid.client.HttpServerInventoryView$2.nodesRemoved(HttpServerInventoryView.java:161)```

<https://github.com/apache/druid/blob/0.23.0/server/src/main/java/org/apache/druid/client/HttpServerInventoryView.java#L172-L184>

It appears that either
```node.getServices()```
or
```((DataNodeService) node.getServices().get(DataNodeService.DISCOVERY_SERVICE_KEY))```
is returning null.

I'm going to see if I can trap this in the debugger and look at the state of the `HttpServerInventoryView` when this occurs.

The NPE is getting caught and produce the error message here <https://github.com/apache/druid/blob/0.23.0/server/src/main/java/org/apache/druid/discovery/DruidNodeDiscoveryProvider.java#L211>

Although is prints an error log, it ignores the actual error.

I am guess this is because the error is non-fatal.

I snagged a screenshot of the node as it is being removed.  Indeed, there are no services listed.

Okay, I think I know what is happening.  As a result of the NPE, the node is not actually removed from the service list.  I think the fix is to put null-safe access on the calls to `((DataNodeService) node.getServices().get(DataNodeService.DISCOVERY_SERVICE_KEY))` at <https://github.com/apache/druid/blob/0.23.0/server/src/main/java/org/apache/druid/client/HttpServerInventoryView.java#L175-L182>

I wonder how the peon `DruidNode` got created without any `services`, that is likely the source of this

I have traced this back to when the peon announcement is received.  It doesn't have any services defined on it.

The indexer-executor announcements contain services but not the peons

According to the source these nodes without services are never stored into the in-memory map <https://github.com/apache/druid/blob/0.23.0/server/src/main/java/org/apache/druid/discovery/DruidNodeDiscoveryProvider.java#L154-L167>

Ok, so from what I can see in the debugger there's no actual bug here.  Peon announcements are ignored, and peon un-announcements are also ignored (albeit through an error log can ignore exception).  I now need to determine why the coordinator is attempting to sync with the node.

That seems to indicate that a `ChangeRequestHttpSyncer` is still running for a segment after the pod hosting that segment has gone away.  I wonder if this is related to segment announcements, not service announcements.

the HttpServerInventoryView is definitely related to segment announcements

the Coordinator does use those to maintain its view of which servers have which segments (so it can manage balancing &amp; replication)

It's bootstrapped from a DruidNodeDiscoveryProvider, which I originally guessed was the problem

It is also possible that the DruidNodeDiscoveryProvider is OK and the issue is that the HttpServerInventoryView doesn't follow changes properly

We had a similar issue with Discovery using ZK. When POD goes down Druid keept trying to old POD. Issue is that it wouldn’t rediscover until DNS fails. When we did nslookup on old pod IP it wasn't giving us server can't find. I suspect it is with POD DNS. Moving from discovering POD from IP to *pod-ip-address.my-namespace.pod.cluster-domain.example* solved the issue for me. I don’t see any config in Kubernetes extension to move from POD discovery from IP to  *pod-ip-address.my-namespace.pod.cluster-domain.example*

what is the nslookup on old IP  (10.4.132.249)  gives

I'm going to start tracing through the DruidNodeDiscoveryProvider and track the segment announce/unannounce and see if I can isolate the issue.  As soon as I can repro and fix it I'll submit a PR upstream.

Picking this investigation up; I have noticed that when a node shuts down and un-announces itself I consistently see a K8s error:
```{"level":"WARN","@timestamp":"2022-09-30T19:39:49.121Z","thread":"Thread-49","message":"Retrying (2 of 2) in 2,504ms.","exception":{"exception_class":"<http://org.apache.druid.java.util.common.RE|org.apache.druid.java.util.common.RE>","exception_message":"Failed to patch pod[cj/storage--druid-coordinator-5bfc57477-vqlqs], code[422], error[{\n  \"kind\": \"Status\",\n  \"apiVersion\": \"v1\",\n  \"metadata\": {\n    \n  },\n  \"status\": \"Failure\",\n  \"message\": \"the server rejected our request due to an error in our request\",\n  \"reason\": \"Invalid\",\n  \"details\": {\n    \n  },\n  \"code\": 422\n}].","stacktrace":"<http://org.apache.druid.java.util.common.RE|org.apache.druid.java.util.common.RE>: Failed to patch pod[cj/storage--druid-coordinator-5bfc57477-vqlqs], code[422], error[{\n  \"kind\": \"Status\",\n  \"apiVersion\": \"v1\",\n  \"metadata\": {\n    \n  },\n  \"status\": \"Failure\",\n  \"message\": \"the server rejected our request due to an error in our request\",\n  \"reason\": \"Invalid\",\n  \"details\": {\n    \n  },\n  \"code\": 422\n}].\n\tat org.apache.druid.k8s.discovery.DefaultK8sApiClient.patchPod(DefaultK8sApiClient.java:71)\n\tat org.apache.druid.k8s.discovery.K8sDruidNodeAnnouncer.lambda$unannounce$2(K8sDruidNodeAnnouncer.java:148)\n\tat org.apache.druid.java.util.common.RetryUtils.retry(RetryUtils.java:129)\n\tat org.apache.druid.java.util.common.RetryUtils.retry(RetryUtils.java:81)\n\tat org.apache.druid.java.util.common.RetryUtils.retry(RetryUtils.java:163)\n\tat org.apache.druid.java.util.common.RetryUtils.retry(RetryUtils.java:153)\n\tat org.apache.druid.k8s.discovery.K8sDruidNodeAnnouncer.unannounce(K8sDruidNodeAnnouncer.java:146)\n\tat org.apache.druid.cli.ServerRunnable$DiscoverySideEffectsProvider$1.stop(ServerRunnable.java:191)\n\tat org.apache.druid.java.util.common.lifecycle.Lifecycle.stop(Lifecycle.java:368)\n\tat org.apache.druid.java.util.common.lifecycle.Lifecycle$1.run(Lifecycle.java:401)\n\tat java.base/java.lang.Thread.run(Thread.java:829)\nCaused by: io.kubernetes.client.openapi.ApiException: Unprocessable Entity\n\tat io.kubernetes.client.openapi.ApiClient.handleResponse(ApiClient.java:993)\n\tat io.kubernetes.client.openapi.ApiClient.execute(ApiClient.java:905)\n\tat io.kubernetes.client.openapi.apis.CoreV1Api.patchNamespacedPodWithHttpInfo(CoreV1Api.java:41306)\n\tat io.kubernetes.client.openapi.apis.CoreV1Api.patchNamespacedPod(CoreV1Api.java:41261)\n\tat org.apache.druid.k8s.discovery.DefaultK8sApiClient.patchPod(DefaultK8sApiClient.java:68)\n\t... 10 more\n"},"hostName":"storage--druid-coordinator-5bfc57477-vqlqs"}```

I looked at the k8s extension, it it is using kubenetes client jar version `11.0.1`, but the latest is `16.0.0`

I'm attempting to update the k8s client jar and fix any breaking changes to see if I can resolve this.

oooo that’s interesting, Kubernetes client is notoriously sensitive to server’s version number, client and server version number must match.
Not sure how the Kubernetes jar is handling that.

that is interesting; i don't know much about k8s client versioning, i hope that updating to the latest from time to time won't cause any other issues

at any rate, i think it makes sense if the official druid extension is built against the latest k8s

I have successfully updated to kubernetes client version 16.0.0 and am testing it now.  So far I needed to make 2 small changes to the existing extension and otherwise it's behaving.

I believe I am ready to begin the PR process!!!

<https://apachedruidworkspace.slack.com/archives/C030CMF6B70/p1664835967306629>

<@U0344FW86DD> consider this me officially volunteering to adopt the kubernetes extension as the maintainer.  We will be continuing to operate it inside our production clusters and perform upstream maintenance and expansion.

try adding `--no-default-remote-repositories` too

without that, your provided repo is only used for stuff that isn't found in the default repos

(from <https://druid.apache.org/docs/latest/operations/pull-deps.html>)

note; similar thread here, i wonder if you are running into the same thing? <https://apachedruidworkspace.slack.com/archives/C0303FDCZEZ/p1663739533640179>

Hi, <@U0344FW86DD> in the logs first it's going to the repo that we mention with `-r`  but even after downloading from that specified repo it again tries to download from repo.maven that is where we're getting this SocketTimeout because it's not allowed with the corporate firewall.But the thing is that if we've specified the remote repo then it should not go to that maven <http://repo.Is|repo.Is> there some issue with the druid ?

I don't see a problem in the code about this, although I haven't tried this exact setup myself 

I don't see any references in our code to <http://repo.maven.apache.org|repo.maven.apache.org> though, which is why i was wondering if your repo was somehow delegating to that one for objects it didn't have locally

If you specify no default remote repositories, and don't provide your own remote (so it'll be local only) -- do you still see it trying to contact <http://repo.maven.apache.org|repo.maven.apache.org>?

yes even after providing`--no-default-remote-repositories -r "<http://repo.xyz|repo.xyz>"`  it is first going to this repo which is specified with this `-r` option and then even after downloading from this remote repo it's again going to that maven repo and also the call to that maven artifact is happening  with `http` call.

I meant if you provide `--no-default-remote-repositories` and no `-r` — in that case it should be purely local resolution

I'm wondering if that still tries to make network calls for some reason

`java  -Dlog4j2.level=DEBUG \`
  `-cp "lib/*" \`
  `-Ddruid.extensions.directory="extensions" \`
  `-Ddruid.extensions.hadoopDependenciesDir="hadoop-dependencies" \`
  `org.apache.druid.cli.Main tools pull-deps \`
  `-c "org.apache.druid.extensions:druid-hdfs-storage:0.23.0" \`
  `-h "org.apache.hadoop:hadoop-client:2.8.5" \`
  `-h "org.apache.hadoop:hadoop-client:3.3.3"`  tried this command attaching the logs below

Downloading artifact org.apache.httpcomponents:httpclient:pom:4.5.13 from  (<https://repo1.maven.org/maven2/>, releases+snapshots)
23:53:11.199 [main] DEBUG org.eclipse.aether.internal.impl.DefaultRepositoryConnectorProvider - Using connector AetherRepositoryConnector with priority 3.4028235E38 for <https://repo1.maven.org/maven2/>
Downloading: <https://repo1.maven.org/maven2/org/apache/httpcomponents/httpclient/4.5.13/httpclient-4.5.13.pom>
Downloaded: <https://repo1.maven.org/maven2/org/apache/httpcomponents/httpclient/4.5.13/httpclient-4.5.13.pom> (7 KB at 6.8 KB/sec)
Downloaded artifact org.apache.httpcomponents:httpclient:pom:4.5.13 from  (<https://repo1.maven.org/maven2/>, releases+snapshots)
Resolved artifact org.apache.httpcomponents:httpclient:pom:4.5.13 from  (<https://repo1.maven.org/maven2/>, releases+snapshots)
Downloading artifact org.apache.httpcomponents:httpclient:pom:4.5.13 from apache.snapshots (<https://repository.apache.org/snapshots>, releases+snapshots)
23:53:12.149 [main] DEBUG org.eclipse.aether.internal.impl.DefaultRepositoryConnectorProvider - Using connector AetherRepositoryConnector with priority 3.4028235E38 for <https://repository.apache.org/snapshots>
Downloading: <https://repository.apache.org/snapshots/org/apache/httpcomponents/httpclient/4.5.13/httpclient-4.5.13.pom>
io.tesla.aether.connector.ResourceDoesNotExistException: Unable to locate resource <https://repository.apache.org/snapshots/org/apache/httpcomponents/httpclient/4.5.13/httpclient-4.5.13.pom>. Error code 404

from the above logs we can see that even after once downloading it again goes to multiple repos and it should not happen since it has already downloaded that particular file

Downloading: <https://repo1.maven.org/maven2/org/apache/httpcomponents/httpclient/4.5.13/httpclient-4.5.13.pom>
Downloaded: <https://repo1.maven.org/maven2/org/apache/httpcomponents/httpclient/4.5.13/httpclient-4.5.13.pom> (7 KB at 6.8 KB/sec)
Downloaded artifact org.apache.httpcomponents:httpclient:pom:4.5.13 from  (<https://repo1.maven.org/maven2/>, releases+snapshots)
Resolved artifact org.apache.httpcomponents:httpclient:pom:4.5.13 from  (<https://repo1.maven.org/maven2/>, releases+snapshots)
Downloading artifact org.apache.httpcomponents:httpclient:pom:4.5.13 from apache.snapshots (<https://repository.apache.org/snapshots>, releases+snapshots)
23:53:12.149 [main] DEBUG org.eclipse.aether.internal.impl.DefaultRepositoryConnectorProvider - Using connector AetherRepositoryConnector with priority 3.4028235E38 for <https://repository.apache.org/snapshots>
Downloading: <https://repository.apache.org/snapshots/org/apache/httpcomponents/httpclient/4.5.13/httpclient-4.5.13.pom>
io.tesla.aether.connector.ResourceDoesNotExistException: Unable to locate resource <https://repository.apache.org/snapshots/org/apache/httpcomponents/httpclient/4.5.13/httpclient-4.5.13.pom>. Error code 404
        at io.tesla.aether.connector.AetherRepositoryConnector.handleResponseCode(AetherRepositoryConnector.java:298)
        at io.tesla.aether.connector.AetherRepositoryConnector.access$900(AetherRepositoryConnector.java:85)
        at io.tesla.aether.connector.AetherRepositoryConnector$GetTask.resumableGet(AetherRepositoryConnector.java:549)
        at io.tesla.aether.connector.AetherRepositoryConnector$GetTask.run(AetherRepositoryConnector.java:391)
        at io.tesla.aether.connector.AetherRepositoryConnector.get(AetherRepositoryConnector.java:232)
        at org.eclipse.aether.internal.impl.DefaultArtifactResolver.performDownloads(DefaultArtifactResolver.java:535)
        at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolve(DefaultArtifactResolver.java:436)
        at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifacts(DefaultArtifactResolver.java:262)
        at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifact(DefaultArtifactResolver.java:239)
        at org.apache.maven.repository.internal.DefaultArtifactDescriptorReader.loadPom(DefaultArtifactDescriptorReader.java:320)
        at org.apache.maven.repository.internal.DefaultArtifactDescriptorReader.readArtifactDescriptor(DefaultArtifactDescriptorReader.java:217)
        at org.eclipse.aether.internal.impl.DefaultDependencyCollector.process(DefaultDependencyCollector.java:461)
        at org.eclipse.aether.internal.impl.DefaultDependencyCollector.process(DefaultDependencyCollector.java:573)
        at org.eclipse.aether.internal.impl.DefaultDependencyCollector.process(DefaultDependencyCollector.java:573)
        at org.eclipse.aether.internal.impl.DefaultDependencyCollector.collectDependencies(DefaultDependencyCollector.java:261)
        at org.eclipse.aether.internal.impl.DefaultRepositorySystem.resolveDependencies(DefaultRepositorySystem.java:342)
        at io.tesla.aether.internal.DefaultTeslaAether.resolveArtifacts(DefaultTeslaAether.java:289)
        at org.apache.druid.cli.PullDependencies.downloadExtension(PullDependencies.java:407)
        at org.apache.druid.cli.PullDependencies.downloadExtension(PullDependencies.java:365)
        at org.apache.druid.cli.PullDependencies.run(PullDependencies.java:311)
        at org.apache.druid.cli.Main.main(Main.java:114)
Downloaded artifact org.apache.httpcomponents:httpclient:pom:4.5.13 from apache.snapshots (<https://repository.apache.org/snapshots>, releases+snapshots)
Downloading artifact org.apache.httpcomponents:httpclient:pom:4.5.13 from sigar (<https://repository.mulesoft.org/nexus/content/repositories/public>, releases+snapshots)
23:53:17.594 [main] DEBUG org.eclipse.aether.internal.impl.DefaultRepositoryConnectorProvider - Using connector AetherRepositoryConnector with priority 3.4028235E38 for <https://repository.mulesoft.org/nexus/content/repositories/public>
Downloading: <https://repository.mulesoft.org/nexus/content/repositories/public/org/apache/httpcomponents/httpclient/4.5.13/httpclient-4.5.13.pom>
Downloaded: <https://repository.mulesoft.org/nexus/content/repositories/public/org/apache/httpcomponents/httpclient/4.5.13/httpclient-4.5.13.pom> (7 KB at 4.2 KB/sec)
Downloaded artifact org.apache.httpcomponents:httpclient:pom:4.5.13 from sigar (<https://repository.mulesoft.org/nexus/content/repositories/public>, releases+snapshots)
Resolved artifact org.apache.httpcomponents:httpclient:pom:4.5.13 from sigar (<https://repository.mulesoft.org/nexus/content/repositories/public>, releases+snapshots)
Downloading artifact org.apache.httpcomponents:httpclient:pom:4.5.13 from central (<http://repo.maven.apache.org/maven2>, releases)
23:53:19.149 [main] DEBUG org.eclipse.aether.internal.impl.DefaultRepositoryConnectorProvider - Using connector AetherRepositoryConnector with priority 3.4028235E38 for <http://repo.maven.apache.org/maven2>
`Downloading: <http://repo.maven.apache.org/maven2/org/apache/httpcomponents/httpclient/4.5.13/httpclient-4.5.13.pom>`   *here in the last line it's making http call, even after downloading*

what if you do that same command but add `--no-default-remote-repositories`?

Added this `--no-default-remote-repositories`  it's failing, if we provide --no-default-remote-repositories than it's mandatory to provide the remote repo...Attaching the logs below

01:26:50.983 [main] INFO  org.apache.druid.cli.PullDependencies - Start downloading dependencies for extension coordinates: [[org.apache.druid.extensions:druid-hdfs-storage:0.23.0]]
01:26:50.985 [main] INFO  org.apache.druid.cli.PullDependencies - Directory [/home/ashish/apache-druid-0.23.0/extensions/druid-hdfs-storage] already exists, skipping creating a directory
01:26:50.989 [main] INFO  org.apache.druid.cli.PullDependencies - Start downloading extension [org.apache.druid.extensions:druid-hdfs-storage:jar:0.23.0]
Resolving artifact org.apache.druid.extensions:druid-hdfs-storage:pom:0.23.0
Resolved artifact org.apache.druid.extensions:druid-hdfs-storage:pom:0.23.0 from null
Missing artifact descriptor for org.apache.druid.extensions:druid-hdfs-storage:jar:0.23.0
01:26:51.008 [main] DEBUG org.eclipse.aether.internal.impl.DefaultDependencyCollector - Dependency collection stats: {ConflictMarker.analyzeTime=1, ConflictMarker.markTime=0, ConflictMarker.nodeCount=1, ConflictIdSorter.graphTime=0, ConflictIdSorter.topsortTime=0, ConflictIdSorter.conflictIdCount=1, ConflictIdSorter.conflictIdCycleCount=0, ConflictResolver.totalTime=4, ConflictResolver.conflictItemCount=1, DefaultDependencyCollector.collectTime=10, DefaultDependencyCollector.transformTime=6}
Resolving artifact org.apache.druid.extensions:druid-hdfs-storage:jar:0.23.0
Resolved artifact org.apache.druid.extensions:druid-hdfs-storage:jar:0.23.0 from null
01:26:51.012 [main] ERROR org.apache.druid.cli.PullDependencies - Unable to resolve artifacts for [org.apache.druid.extensions:druid-hdfs-storage:jar:0.23.0 (runtime) -&gt; [] &lt; []].
org.eclipse.aether.resolution.DependencyResolutionException: Could not find artifact org.apache.druid.extensions:druid-hdfs-storage:jar:0.23.0
        at org.eclipse.aether.internal.impl.DefaultRepositorySystem.resolveDependencies(DefaultRepositorySystem.java:384) ~[aether-impl-0.9.0.M2.jar:?]
        at io.tesla.aether.internal.DefaultTeslaAether.resolveArtifacts(DefaultTeslaAether.java:289) ~[tesla-aether-0.0.5.jar:0.0.5]
        at org.apache.druid.cli.PullDependencies.downloadExtension(PullDependencies.java:407) [druid-services-0.23.0.jar:0.23.0]
        at org.apache.druid.cli.PullDependencies.downloadExtension(PullDependencies.java:365) [druid-services-0.23.0.jar:0.23.0]
        at org.apache.druid.cli.PullDependencies.run(PullDependencies.java:311) [druid-services-0.23.0.jar:0.23.0]
        at org.apache.druid.cli.Main.main(Main.java:114) [druid-services-0.23.0.jar:0.23.0]
Caused by: org.eclipse.aether.resolution.ArtifactResolutionException: Could not find artifact org.apache.druid.extensions:druid-hdfs-storage:jar:0.23.0
        at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolve(DefaultArtifactResolver.java:459) ~[aether-impl-0.9.0.M2.jar:?]
        at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifacts(DefaultArtifactResolver.java:262) ~[aether-impl-0.9.0.M2.jar:?]
        at org.eclipse.aether.internal.impl.DefaultRepositorySystem.resolveDependencies(DefaultRepositorySystem.java:367) ~[aether-impl-0.9.0.M2.jar:?]
        ... 5 more
Caused by: org.eclipse.aether.transfer.ArtifactNotFoundException: Could not find artifact org.apache.druid.extensions:druid-hdfs-storage:jar:0.23.0
        at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolve(DefaultArtifactResolver.java:449) ~[aether-impl-0.9.0.M2.jar:?]
        at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifacts(DefaultArtifactResolver.java:262) ~[aether-impl-0.9.0.M2.jar:?]
        at org.eclipse.aether.internal.impl.DefaultRepositorySystem.resolveDependencies(DefaultRepositorySystem.java:367) ~[aether-impl-0.9.0.M2.jar:?]
        ... 5 more
Exception in thread "main" java.lang.RuntimeException: java.lang.RuntimeException: org.eclipse.aether.resolution.DependencyResolutionException: Could not find artifact org.apache.druid.extensions:druid-hdfs-storage:jar:0.23.0
        at org.apache.druid.cli.PullDependencies.run(PullDependencies.java:335)
        at org.apache.druid.cli.Main.main(Main.java:114)
Caused by: java.lang.RuntimeException: org.eclipse.aether.resolution.DependencyResolutionException: Could not find artifact org.apache.druid.extensions:druid-hdfs-storage:jar:0.23.0
        at org.apache.druid.cli.PullDependencies.downloadExtension(PullDependencies.java:420)
        at org.apache.druid.cli.PullDependencies.downloadExtension(PullDependencies.java:365)
        at org.apache.druid.cli.PullDependencies.run(PullDependencies.java:311)
        ... 1 more
Caused by: org.eclipse.aether.resolution.DependencyResolutionException: Could not find artifact org.apache.druid.extensions:druid-hdfs-storage:jar:0.23.0
        at org.eclipse.aether.internal.impl.DefaultRepositorySystem.resolveDependencies(DefaultRepositorySystem.java:384)
        at io.tesla.aether.internal.DefaultTeslaAether.resolveArtifacts(DefaultTeslaAether.java:289)
        at org.apache.druid.cli.PullDependencies.downloadExtension(PullDependencies.java:407)
        ... 3 more
Caused by: org.eclipse.aether.resolution.ArtifactResolutionException: Could not find artifact org.apache.druid.extensions:druid-hdfs-storage:jar:0.23.0
        at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolve(DefaultArtifactResolver.java:459)
        at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifacts(DefaultArtifactResolver.java:262)
        at org.eclipse.aether.internal.impl.DefaultRepositorySystem.resolveDependencies(DefaultRepositorySystem.java:367)
        ... 5 more
Caused by: org.eclipse.aether.transfer.ArtifactNotFoundException: Could not find artifact org.apache.druid.extensions:druid-hdfs-storage:jar:0.23.0
        at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolve(DefaultArtifactResolver.java:449)
        ... 7 more

Seems be a issue from druid pull-deps making use of the AetherRepositoryConnector