Apache Druid

This error generally happens between broker to historical communication.
Can you please check if that's okay ?

I see this call  `refreshSegmentsForDataSource` failed during this time, but am not sure if this is related

refreshSegmentsForDataSource pulls data from the historicals to create the sys segment view .

oh i see. I will have to check logs in detail, as it was auto-recovered.

8000 is a large number of explicit columns in the table ... are these coming in as individually named columns?

If much of this is attributes coming in JSON format, especially if the JSON changes from row to row, I suggest you look at nested columm support as something to potentially try.

If these columns contain flattened array elements, there is some work on "true" array storage coming up in the product, I don't know too much about it but you can ask more specific questions about it in the "general" forum.

The 8000 columns are individual named columns 

We are facing performance issues when we patch the Druid database as data accumulate in Kafka and there are tons and tons of data flow in once patching is done, causing some of the process to hang 

nested columns or JSON&lt;Complex&gt; types would be a better type to use.  We also store 6-7K columns at a rate of 2-3 Million records per second.  I would imagine with 8K flattened columns your intermediatePersists on the MM's are likely taking dozens of seconds thus slowing down your ingest rate.     <https://druid.apache.org/docs/latest/querying/nested-columns.html>

The coordinator and historical getting hung is a seperate issue entirely, but the above should alleviate the ingest issues ur facing

Is there anything I need to look into for such scenario 

What is your segment granularity, and what is the overall volume within that granularity?  How many segments overall in the datasource?

I routinely work with clusters that have 100-300k segments in them ... individual datasources spanning a years time with 1000-50000 segments in them.  You can sustain a wide range here without much affect on query performance ... but it also depends heavily on what your queries are.

If you could provide a bit more info that would be helpful.

I would say trust sql based ingestion :slightly_smiling_face: .
Do clustered by event_type using a replace.
For eg : <https://druid.apache.org/docs/latest/multi-stage-query/examples.html#replace-for-replacing-a-specific-time-segment>

If the segment sizes created by the job vary a lot, then you can use the undocumented `clusterStatisticsMergeMode=SEQUENTIAL` context parameter .

So we do ingest data via Kafka, and our primary dimension where we apply the filter is eventType. We have 30 minute segment granularity, so for some data-source overall volume within this time is around 5 million. And overall segments for this data-source is around 50K, overall datasize is 1.5TB.

Mostly are queries are against a specific eventType, so without compaction for some eventType queries are going through the all data even though number of rows for that event type is just 50K out of 5mil. So if we can partition it via eventType, i am thinking it will be pretty fast and efficient.

<@U0315MQKEHK> What exactly does `clusterStatisticsMergeMode`  do ?, doc just talk about sketch merges .

I think you can ignore `clusterStatisticsMergeMode` for now

But if you want to read about it: <https://github.com/apache/druid/blob/master/extensions-core/multi-stage-query/src/main/java/org/apache/druid/msq/exec/ClusterStatisticsMergeMode.java|https://github.com/apache/druid/blob/master/extensions-core/multi-stage-query/src/[…]/java/org/apache/druid/msq/exec/ClusterStatisticsMergeMode.java>

I did try to single_dim partition on some sample data for 6 hour duration. I gave targetSegmentRows=800K.  Sample data on which i am trying to compact had like 840 segments each has 50K rows.

dimension on which i am trying to partition has the following distribution with in 6 hour.

```service1   3222
service2   353053
service3   9409
service4   159100
service5   5387
service6   5969893
service7   5392```
Interestingly compaction created only 2 segments one with 600K, and other one with 5.9million.

Two problems i see.
• When i check the shardSpec for both segments first one had data for top5 services while the last one had data for bottom 2. i was expecting it to try to create partition for each one seperately.
• why the second segment had 3.8 million rows when i specified the targetRowsPerSemgent to be 800k ? 
<@U0315MQKEHK> <@U04C4593VDY>  Possible for you to help here ?

Not sure if this payload helps which being passed during *partial_range_index_generate* stage. where it seems to creating only 2 partition ? I am just guessing around.

```{
  "2023-04-12T00:00:00.000Z/2023-04-12T01:00:00.000Z": [
    null,
    "service6",
    null
  ],
  "2023-04-12T05:00:00.000Z/2023-04-12T06:00:00.000Z": [
    null,
    "service6",
    null
  ],
  "2023-04-12T01:00:00.000Z/2023-04-12T02:00:00.000Z": [
    null,
    "service6",
    null
  ],
  "2023-04-12T02:00:00.000Z/2023-04-12T03:00:00.000Z": [
    null,
    "service6",
    null
  ],
  "2023-04-12T04:00:00.000Z/2023-04-12T05:00:00.000Z": [
    null,
    "service6",
    null
  ],
  "2023-04-12T03:00:00.000Z/2023-04-12T04:00:00.000Z": [
    null,
    "service6",
    null
  ]
}```

Hi Udit,  the skew in segment sizes I understand is just the imprecision of the algorithm when dealing with not-so-granular value distribution ... one way I've heard to help this is to add a second column, which increases the cardinality of the range and allows for more uniform sizes.

oh okay. Wondering then when the config targetRowsPerSegment used ? i was expecting it to at-least create more partitions once it crosses this limit.  Any idea when it is honoured and when it is not ?

It's a target ... I just don't know the algorithm behind it ... will take me some time to look through the code ...

<@U03NHKDPN3W> Please try this : <https://druid.apache.org/docs/latest/multi-stage-query/examples.html#replace-for-replacing-a-specific-time-segment>

Lot of work is done on the segment sizing piece in MSQ&gt;

When you say it might fix segment sizing, do you mean it will try to honour the targetMaxRows when i say clustered by eventType?

Unfortunately version (*22*) which i am using does not have it, may be i will have upgrade the druid to try it out.

&gt;  When you say it might fix segment sizing, do you mean it will try to honour the targetMaxRows when i say clustered by eventType?
Yup

<@U0315MQKEHK> I was trying out MSQ based ingestion.  I have one doubt though, when we do the index_parallel ingestion we can always gives lock priority to it, which makes sure that if there is real time data incoming  for same  time range the index_parallel task will interrupt and give up for real time ingestion.

Is there a way i can do the same for MSQ based ingestion too. I see this in the documentation for MSQ where it says that other ingestion will not run when the task is running.

&gt; `REPLACE` statements acquire an exclusive write lock to the target time range of the target datasource. No other ingestion or compaction operations may proceed for that time range while the task is running. However, ingestion and compaction operations may proceed for other time ranges.

image.png

<@U0315MQKEHK> I have tried MSQ based ingestion, the config for this was *rowPerSegment=3Mil*. See the segment it created after ingestion.  these are still off in terms of size.  I was thinking if partition 1-5 could have been more compacted so that segment size would be in the suggested range of 300-700MB.

Thanks for tagging me. Somehow it went of my radar.
If you have incoming data in the same time partition from lets say realtime task, while the MSQE job is running on the same time partition, then consider using `Insert`
If you want to do a replace, we take an exclusive lock. I haven't tested it out but if a realtime task creates segment for the same time partition, the replace job should release its lock since its running at a lock priority of 50 and the realtime task runs at a lock prio of 75.

This is re-partitioning the existing data, hence i can not use insert.

Plus Insert will not have segment pruning enabled at broker.

That is what i thought that  MSQE has lower lock priority so it should work. I will also confirm it.

Regarding this :
&gt; I have tried MSQ based ingestion, the config for this was *rowPerSegment=3Mil*. See the segment it created after ingestion.  these are still off in terms of size.  I was thinking if partition 1-5 could have been more compacted so that segment size would be in the suggested range of 300-700MB.
Seems like your row sizes are varying a lot which is the issue. Even then it should be closer to the numRows per segment which should be around 3 million.
Some questions:
• Could you share the rough sql query,
• What version of druid are you on . 
• How many records do you have in your data. 
• How many distinct "timeUnit" do you have in your data. By `timeunit` I mean the partitioned by `timeunit`. So if the replace query is `replace into foo overwrite all select * from bar partitioned by day` then the `timeUnit` is day. 

SQL Query:
```REPLACE INTO "events"
OVERWRITE WHERE __time &gt;= TIMESTAMP '2023-07-20 18:00:00' AND __time &lt; TIMESTAMP '2023-07-20 19:00:00'
SELECT * FROM "events" WHERE __time &gt;= TIMESTAMP '2023-07-20 18:00:00' AND __time &lt; TIMESTAMP '2023-07-20 19:00:00'
PARTITIONED BY HOUR
CLUSTERED BY eventType```
Druid version: 26.0

total records with in the time range: ~8 Million

distinctTimeUnit -&gt; if you mean value of __time then it will be 2.

and whats the `rowsPerSegment` passed ?
there was a typo in the config you set

I even tried with this config you suggested but same result

"clusterStatisticsMergeMode": "SEQUENTIAL"

What's the number of workers you are passing ? or more like ``maxNumTasks``

Since if you have passed these param's then the partition cuts should be around 3 million

I debugged this. Since we have a lot of cols in the data source, we are downsampling the sketch to have similarly sized segments which is intended behaviour. To explain this better there is a PR which is already out so that we users can get better leads as to what's is the downsampling %.

<https://github.com/apache/druid/pull/14580>

Has your streaming supervisor published any segments yet?
Streaming jobs have open segments which are not processed by the coordinator for loading / moving until they have been committed after being published to deep storage

<@U0319HD8HEC> it is continuously emiting the same message and task is running from a long time

I m using ingestion spec to load data from kafka topic to druid 

and my supervisor task is continuing running any ideas??

the segment-level cache key is built from all the stuff that affects segment-level processing :slightly_smiling_face:

It's stuff like intervals, virtual column, filter, aggregations, etc

But generally not stuff like post-aggregations or having filter

The interval for the cache key is clipped to the segment interval, so for example if you query interval is 2000-01-01/2000-01-04, but your segment interval is 2000-01-01/2000-01-02, then for that segment the cache key will be 2000-01-01/2000-01-02 (clipped)

for the scenario you mentioned, we won't leverage cache when you update the query, b/c you're updating a secondary timestamp filter &amp; that changes the cache key (it's part of `filter` which is part of cache key)

hmm i understood, but theoretically we should be able to leverage this cache. Because it does not make sense to calculate the result again. Do you think this could be implemented generically in case of secondary timestamp ? I would be happy to contribute :slightly_smiling_face: I am not much familiar with the druid code base at the moment, so checking if it is feasible and make sense then i could spent sometime on it.

Hmm, this one might be tricky since I am not 100% sure how to do it :slightly_smiling_face:

The general idea is we'd want to prune out filters from the cache key that we know cannot possibly change the results (for example, because they are in an `and` and they are always true)

we have some code to analyze filter domains that we use for pruning segments

check out `DimFilter.getDimensionRangeSet` and the things that call it

It may be possible to use something like this when computing cache key

Sorry i was off work, so could not check back.  sure I will check it.

seems like this prop is not set, where historical will keep the data on local disk

```druid.segmentCache.locations=[{"path":"/var/druid/segment-cache","maxSize":bytes}]```


Hi <@U03NHKDPN3W> thank you for your response 

I have set the mentioned parameter in conf/druid/cluster/data/historical/runtime.properties 

are you running the cluster mode or single server ? may be missing there ?

Can you paste what the value for this  in your config ?

Hi <@U03NHKDPN3W> thank you for your response, the value is 

```druid.segmentCache.locations=[{"path":"/druid/var/druid/segment-cache","maxSize":1000000}]```

Hi Adam,  I just tried this against the wikipedia data source (after I segmented it by HOUR):

```REPLACE INTO wikipedia_part2 OVERWRITE
  WHERE __time &gt;= TIMESTAMP '2023-04-17 00:00:00' AND __time &lt; TIMESTAMP '2023-04-18 00:00:00'
 SELECT CURRENT_TIMESTAMP "__time",
  "isRobot",
  "channel",
  "flags",
  "isUnpatrolled",
  "page",
  "diffUrl",
  "added",
  "comment",
  "commentLength",
  "isNew",
  "isMinor",
  "delta",
  "isAnonymous",
  "user",
  "deltaBucket",
  "deleted",
  "namespace",
  "cityName",
  "countryName",
  "regionIsoCode",
  "metroCode",
  "countryIsoCode",
  "regionName"
  FROM wikipedia_part2 
 WHERE __time &gt;= TIMESTAMP '2016-06-27 00:00:00' AND __time &lt; TIMESTAMP '2016-06-28 00:00:00'
PARTITIONED BY HOUR```
I did an insert/overwrite into a time range that had no segments, but used a select that had data in it ... and I had to change the __time field value to be within the bounds of the time range that I am writing into.  But that worked fine.

If you can't figure out what's going wrong by using the above example as a reference, then please post your SQL and identify which time ranges have existing data and which do not, and we can go from there.

I had seen this problem too, it's fixed by <https://github.com/apache/druid/pull/13955> which will be in 26.0

Prior to that fix, the job can hang if there is no data at all to be read

Hello all, I am getting below error 

druid.segmentCache. locations must be set on historicals.

I am unable to figure out the issue, does anyone have any idea on resolving it ??
Thread in Slack Conversation

I have the druid.segmentCache.locations mentioned in my cluster historical runtime properties file actually 

But still the historical log file says the error 

If you're getting this error it must really not be set. I wonder if the parameter is being set in the right file?

I have same problem while preparing upgrade from 0.22.1 to 25.0.0. For some reason new version of druid didnt load settings from conf/druid/historical/runtime.properties. Has anything changed? I found workaround, rename conf/druid/historical/runtime.properties to conf/druid/historical/common.runtime.properties

That sounds very strange. How is your cluster deployed?

build from source, commit 9a78059ffbb22f0bf6074cd81b13078a2d4501bc (HEAD, tag: druid-25.0.0-rc2, tag: druid-25.0.0), using Maven 3.6.3  by running `mvn clean install -Pdist-hadoop3,hadoop3 -DskipTests` . I had to change ./pom.xml line 1509 from `&lt;resourceBundle&gt;org.apache.apache.resources:apache-jar-resource-bundle:1.5-SNAPSHOT&lt;/resourceBundle&gt;`  to `&lt;resourceBundle&gt;org.apache:apache-jar-resource-bundle:1.5-SNAPSHOT&lt;/resourceBundle&gt;` . Then I unpack apache-druid-25.0.0-bin.tar.gz on target servers ( bare metals, AlmaLinux release 8.7 and java `openjdk version "1.8.0_372"`
`OpenJDK Runtime Environment (build 1.8.0_372-b07)`
`OpenJDK 64-Bit Server VM (build 25.372-b07, mixed mode)` ), copy current configs from  my production instance(druid 0.22.1): conf/druid/_common/common.runtimes.properties, conf/druid/historical/{jvm.config, runtime.properties} and after run druid-historical (bin/historical.sh start) noticed, that parameters set in conf/druid/historical/runtime.properties has no  effect. After move conf/druid/historical/runtime.properties to conf/druid/historical/common.runtime.properties  settings from conf/druid/historical/common.runtime.properties appear in log and service started

i'm not aware of anything changing in Druid itself here. the main code always loads both `common.runtime.properties` and `runtime.properties` from the classpath

could be something changed in a start script?

Screenshot 2023-04-17 at 4.11.19 PM.png

I believe disk space can be controlled by `druid.indexer.task.baseDir`  But i would suggest to try running with more `Max tasks`

Details:
Memory Usage: <https://druid.apache.org/docs/latest/multi-stage-query/concepts.html#memory-usage>
Disk Usage:
<https://druid.apache.org/docs/latest/multi-stage-query/concepts.html#disk-usage>

Thanks <@U03R5H3B750> for helping.
But I am still unable to understand why this process is so much memory consuming, although we do not have that much of data.

btw, spill to disk happens automatically with MSQ, see <https://druid.apache.org/docs/latest/multi-stage-query/concepts.html#memory-usage>

sizing is also automatic if you use druid's `bin/start-druid` command to run it

by default the script will configure druid to use most of the memory on the machine, it's possible you are seeing that

if you prefer it to use less you can use the `-m` switch

<@U053LJ3SXD2> I found below in one of the previous occurrence:
Please try this : To correctly use the combining input source, you need to specify the value of `maxNumConcurrentSubTasks` in `tuningConfig` to be atleast 2. Otherwise, the task goes into sequential mode and fails.

If it is not set, the default value for `maxNumConcurrentSubTasks` is 1

<@U03R5H3B750> That has worked! Thank you very much.

Glad to hear that. Thanks to <@U0318CX1NH4> Who actually found out the solution.

I am seeing in druid-ui data sources page its saying segments to load for nee segments but in coordinator log I don’t see any assignment logs 

This is happening after I upgraded to druid 25

Any error/messages in the coordinator log?
IS their any change in deep storage location?
The coordinator detects new segments which are being pushed by the tasks to the deep storage.
Could we just restart the master node and see if this finds the correct path from where to load the segments.

Restarting coordinator is only loading segments till restart time

As it is loading the segments for the time of restart that means it is something to do with the load rule/period causing the issue. Check what value is set for `druid.coordinator.period`

Below links should help: on setting the correct values for coordinator loading parameters:
<https://druid.apache.org/docs/latest/configuration/index.html#coordinator-operation>
<https://druid.apache.org/docs/latest/configuration/index.html#metadata-retrieval>

our coordinator period is PT60S. i think its not respecting that

Yeah the period looks to be default value. Is it possible to post the coordinator log and config file?

its detecting new segments but not loading i am not seeing assigning for new segments
```Apr 18, 2023 @ 09:52:07.622	[2023-04-18T04:22:04.564Z] INFO DatabaseRuleManager-Exec--0 SQLMetadataRuleManager:105 Polled and found 10 rule(s) for 5 datasource(s)
	Apr 18, 2023 @ 09:51:47.591	[2023-04-18T04:21:46.513Z] INFO org.apache.druid.metadata.SqlSegmentsMetadataManager-Exec--0 SqlSegmentsMetadataManager:105 Polled and found 84,882 segments in the database```

Screenshot 2023-04-18 at 10.00.54 AM.png

ok, there are 10 rules set for the 5 datasources, check for the rules, is it set properly to load the segments. try checking coordinator dynamic config below two parameter two load the segments.

i observed now that coordinator is loading segments after every one hour from the coordinator logs

is some default config changes causing this in druid 25.0

how frequently coordinator checks for new segments in Metadata in druid
is there any config for the same apart from
DRUID_COORDINATOR_PERIOD which is already set to 1m

The link provided earlier does have those settings: <https://druid.apache.org/docs/latest/configuration/index.html#metadata-retrieval>

Hi, Can you check `Max non primary replicants to load` in the Coordinator dynamic properties and set to a lower value.
This we can check if the coordinator is busy is assigning replicas

Pls check if you have lot of unused segments, if that is the case then disable auto kill tasks in coordinator runtime properties and restart coordinator process,

it was on in the 0.22.1 cluster with PT2H
is there any specific reason for changing this in druid 25

Does kill task is enabled in your cluster?

okay, did you also configured as how long segments to cleanup, any duration? `druid.coordinator.kill.durationToRetain`

Ok, idk what is the problem but sometime coordinator unable to assign the segment load if there are too many unused segments. so, by disabling the kill task, you can confirm.

I believe thats the table we have ldap info , are those mapping /roles are created for ldap or basic auths

<@U03QYUNNFCN> I renamed the druid_config table also but nothing affected, still LDAP is enabled, and the table is not created again after the druid services restarted

looks weird ,   did you removed configs from common runtime . Any error you see in coordinator logs . if anyone faced same issue here ?

Yes I removed and all stopped services but still same issue

<@U03QYUNNFCN> let me know if u have some time

there's also a local disk cache in `druid.auth.basic.common.cacheDirectory` if you have set that property

we already turned off DNS caching at JVM level for all services.

Can you explain why this will help, wanted to understand the reason  ? 
I already made it like 500k, which seems like a reasonable number to me and avg event size is around 800 bytes.

Druid has a limit of 2 GB column size, as per error the number of rows inserting in one segment is increasing than 2 GB.

Limit of 2Gb per column , is it segment size or a specific column size limit with in row  ?

I didn’t find any documentation yet for the column inside segment, I believe the size of the entire segment. Check below screen shot from guide:
<https://druid.apache.org/docs/latest/design/segments.html#segment-components>

Hi <@U03R5H3B750> i need help for understand too, so the limit of column size for one row in segment is 2Gb? I’m still confused

Hi Eddie,

I did not find any documentation on this but as per above screen shot it should be. Druid stores data in column format, so that smoosh file which will have the binary data should be 2 GB or less.

Oh thanks me either I failed to find doc on it

IMG_1613.jpg

Is there data loaded on this cluster? Those are INFO messages, so there isn't necessarily a problem. What are you expecting to see?

I m trying to ingest data using ingestion spec. it has only 1 lakh rows it is running from a long time and then after a while my system freeze any idea why that might be happening?

DO you see any error in taks logs and overlord logs for more details .

Hi, As per the screenshot, it is not showing any used segments that can be loaded in the coordinator logs.
You can start with the tasks logs and see if any segments are getting published.

Definitely look at the overlord and ingestion task logs, I suspect you have a problem with publishing to deep storage. Could be something with deep storage config or metadata DB config. The logs will show the problem. Are you using streaming ingestion or batch ingestion?

would really need some assistance in this

By zero duration I mean if I manage to construct a timeseries query with granularity P1D but intervals
```  "intervals": {
    "type": "intervals",
    "intervals": [
      "2023-01-01T00:10:00.000Z/2023-01-01T00:10:00.000Z"
    ]
  }```

I would expect to get zero buckets. But what actually happens is I get a month of daily buckets.

I've tried a few things like `2023-01-01T06:00:00Z/PT0H0M0S` which sort of works, if my begin time is aligned somehow, but if it is ever offset it just returns more stuff.

We've settled on, if we detect ourselves about to run a query with a same begin and end date or out of order, we will just query for the interval `3000-01-01T00:00:00Z/3000-01-01T00:00:00Z` which theoretically should return an empty result and no buckets (I hope). But it feels like a real hack.

I've heard this has something to do with Zookeeper purge activity ...

This is a bug, it seems to be due to some erroneous calculations for zero-length intervals in the segment lookup. The data isn't being clipped properly.

You can work around it in a slightly less hacky way by doing:

```  "intervals": {
    "type": "intervals",
    "intervals": []
  }```

raised an issue— <https://github.com/apache/druid/issues/14129>

That is an solution that I never would have though of.

A fix: <https://github.com/apache/druid/pull/14136>

Screenshot 2023-04-19 at 11.30.43 AM.png

Please check overlord and see if any error for this task.

pls assume the fieldname and name are correctly defined. i have made a type in the above query

I got some hint, by default the bound filter compares based on lexicographic order and by changing that to numeric i am getting expected result
```{
  "type": "bound",
   "dimension": "accessCount_hll",
   "lower": 203,
   "lowerStrict": false,
   "ordering": "numeric"
}```
but still trying to understand how that affects the query

with this config
```{"type": "bound",,
  "lower": 1,
  "lowerStrict": false,
  "ordering": "lexicographic"
}```
output:
```emailid       |    accessCount_hll
<mailto:a1@abc.com|a1@abc.com>    |         210
<mailto:a2@abc.com|a2@abc.com>    |         200
<mailto:a3@abc.com|a3@abc.com>    |         199
...
<mailto:a3@abc.com|a3@abc.com>    |         3```
#2
with this config
```{"type": "bound",,
  "lower": 2,
  "lowerStrict": false,
  "ordering": "lexicographic"
}```
output:
```emailid       |    accessCount_hll
<mailto:a1@abc.com|a1@abc.com>    |         210
<mailto:a2@abc.com|a2@abc.com>    |         200
<mailto:a3@abc.com|a3@abc.com>    |         3```
#3
with this config
```{"type": "bound",,
  "lower": 3,
  "lowerStrict": false,
  "ordering": "lexicographic"
}```
output:
```emailid       |    accessCount_hll
<mailto:a3@abc.com|a3@abc.com>    |         3```


lexicographic order causes string comparisons rather than numeric comparisons, so "3  "&gt;"203"

it looks like the MiddleManager is not starting the Peon process, but I don't know how to solve that

Can you share your middle manager configuration?

Do you see any errors in the middle manager log?

MiddleManager-partial-log.txt

Hello <@U030K4UM3H7>, I've found this in the MiddleManager log:

middlemanager runtime.properties
```#
# Licensed to the Apache Software Foundation (ASF) under one
# or more contributor license agreements.  See the NOTICE file
# distributed with this work for additional information
# regarding copyright ownership.  The ASF licenses this file
# to you under the Apache License, Version 2.0 (the
# "License"); you may not use this file except in compliance
# with the License.  You may obtain a copy of the License at
#
#   <http://www.apache.org/licenses/LICENSE-2.0>
#
# Unless required by applicable law or agreed to in writing,
# software distributed under the License is distributed on an
# "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
# KIND, either express or implied.  See the License for the
# specific language governing permissions and limitations
# under the License.
#

druid.service=druid/middleManager
druid.plaintextPort=8091

# Number of tasks per middleManager
druid.worker.capacity=2

# Task launch parameters
druid.indexer.runner.javaCommand=bin/run-java
druid.indexer.runner.javaOptsArray=["-server","-Xms1g","-Xmx1g","-XX:MaxDirectMemorySize=1g","-Duser.timezone=UTC","-Dfile.encoding=UTF-8","-XX:+ExitOnOutOfMemoryError","-Djava.util.logging.manager=org.apache.logging.log4j.jul.LogManager"]
druid.indexer.task.baseTaskDir=var/druid/task

# HTTP server threads
druid.server.http.numThreads=12

# Processing threads and buffers on Peons
druid.indexer.fork.property.druid.processing.numMergeBuffers=2
druid.indexer.fork.property.druid.processing.buffer.sizeBytes=100MiB
druid.indexer.fork.property.druid.processing.numThreads=2

# Hadoop indexing
druid.indexer.task.hadoopWorkingPath=var/druid/hadoop-tmp```

Do you see any log entries at: `var/druid/task/index_kafka_meiosdepagamento__db_claro_flex_app_payment_f9f367b8ffde949_dehnfdae/log` That's probably under /opt/druid/var...

no, it's not there, I will start the supervisor again and see if it is created

I'm suspecting some configuration problem that's preventing the task for initiating properly. An exit code of 2 for a JVM means it could not execute, so if any logging is done it would be useful. Otherwise, you can probably see the error by trying to run the command manually on that node so you can see its output directly
• from /opt/druid (in case there is any dependency on the starting location) run the whole bin/run_java
```(I'm trying to paste it here, but it is too big)```

this the full content of the `log` file from `index_kafka_meiosdepagamento__db_claro_flex_app_payment_63c0415f85179dd_jpcohiih` folder

when is too big, you must create a text file and upload it

probably I need to copy that gigantic line from the log, right?

command.txt

sorry. and thanks, now I know how to deal with big text.

```Error: Could not find or load main class druid-kafka-indexing-service,
Caused by: java.lang.ClassNotFoundException: druid-kafka-indexing-service,
bash: -Ddruid.selectors.coordinator.serviceName=druid/coordinator: No such file or directory
bash-5.1$```

perhaps I need to quote `druid/coordinator` there?

I'm trying to make sense of it. Does the folder druid-kafka-indexing-service folder exist under /opt/druid/extensions?

it is the official Druid 25.0.0 Docker image

so, you should definitely not have this problem. I've never seen it. Can you share your docker run command?

are you running this in a cluster of single docker image running standalone?

```docker run -it --env-file ~/code/data-adapter-data-lake/druid/.env --name zookeeper -p 2181:2181 -v /home/eggert/code/data-adapter-data-lake/druid/conf/zk:/conf --network druid-net zookeeper:3.8.1
docker run -it --env-file ~/code/data-adapter-data-lake/druid/.env --name master -p 8081:8081 -p 1527:1527 -p 8090:8090 -v /home/eggert/code/data-adapter-data-lake/druid/conf:/opt/druid/conf  --entrypoint /opt/druid/conf/start_master.sh --network druid-net apache/druid:25.0.0
docker run -it --env-file ~/code/data-adapter-data-lake/druid/.env --name historical -p 8083:8083 -v /home/eggert/code/data-adapter-data-lake/druid/conf:/opt/druid/conf --entrypoint /opt/druid/conf/start_historical.sh  --network druid-net apache/druid:25.0.0
docker run -it --env-file ~/code/data-adapter-data-lake/druid/.env --name middle -p 8091:8091 -p 8100-8199:8100-8199 -v /home/eggert/code/data-adapter-data-lake/druid/conf:/opt/druid/conf --entrypoint /opt/druid/conf/start_middle.sh --network druid-net apache/druid:25.0.0
docker run -it --env-file ~/code/data-adapter-data-lake/druid/.env --name router -p 8088:8088 -p 8888:8888 -v /home/eggert/code/data-adapter-data-lake/druid/conf:/opt/druid/conf --entrypoint /opt/druid/conf/start_router.sh  --network druid-net apache/druid:25.0.0
docker run -it --env-file ~/code/data-adapter-data-lake/druid/.env --name broker -p 8082:8082 -v /home/eggert/code/data-adapter-data-lake/druid/conf:/opt/druid/conf --entrypoint /opt/druid/conf/start_broker.sh  --network druid-net apache/druid:25.0.0```

I'm running every container in a separete terminal, to see the output

first I was trying with single-server, but was having the same issue... (reported in the beginning of this thread)

I just couldn't make work with the default entrypoint

so I've created those startup scripts and changed the entrypoint

Have you tried docker compose? or the helm chart on minikube?

docker compose -&gt; <https://github.com/apache/druid/tree/master/distribution/docker>

if you want to try your hand at minikube, I did this on 0.23.0 here: <https://imply.io/blog/apache-druid-for-preppers/>

no, I haven't... I need to move this to an ECS cluster later, and it was not clear to me how to do that using the docker compose as startup point

so maybe the minikube path makes more sense. I'm really not sure what's going on with the task there, seems like the classpath isn't complete when running the peon JVM, but I'm not sure why.

I have tested kafka ingestion locally by running quickstart and following the <https://druid.apache.org/docs/latest/tutorials/tutorial-kafka.html|kafka tutorial>. Not sure what your objective is, but that might also help.

that's a path to... I use MSK with SASL + Schema Registry, and strugled a lot with the quickstart

but now I know what needs to be done to make this to work, so the quickstart migth help to

Druid 25.0.0 has some great features. And I’ve been using it a lot. So unless this is a docker image issue. I would say go with 25.

I can build my own docker image from scratch, downloading Druid 25.0.0 and unpacking it

you use the docker hub image for 25.0.0 or the tar.gz download?

great, I appreciate your help <@U030K4UM3H7> ... thank you very much, lots of ideas to solve this

You could use this docker compose file <https://github.com/apache/druid/blob/25.0.0/distribution/docker/docker-compose.yml>

Hello <@U030K4UM3H7>, I've created a Docker image from scratch, using Alpine, downloading/installing JRE and a few stuff for connection troubleshoot, downloaded Druid 25.0.0 and after starting up everything, just got the same behavior

In the end, the error for not loading the class was the `druid.server.hiddenProperties` that had some white spaces

but, also with solving that, I still can't ingest from my kafka, but I have some new error message

I ran the peon java command from the middlemanager node

this is the error:
```2023-04-20T19:50:38,030 INFO [main] org.apache.druid.guice.JsonConfigurator - Unable to parse value of property [druid.extensions.loadList] as a json object, using as is.
Exception in thread "main" com.google.inject.ProvisionException: Unable to provision, see the following errors:

1) Problem parsing object at prefix[druid.extensions]: Cannot deserialize instance of `java.util.LinkedHashSet&lt;java.lang.Object&gt;` out of VALUE_STRING token
 at [Source: UNKNOWN; line: -1, column: -1] (through reference chain: org.apache.druid.guice.ExtensionsConfig["loadList"]).
  at org.apache.druid.guice.JsonConfigProvider.bind(JsonConfigProvider.java:151)
  at org.apache.druid.guice.JsonConfigProvider.bind(JsonConfigProvider.java:151)
  while locating com.google.common.base.Supplier&lt;org.apache.druid.guice.ExtensionsConfig&gt;
  at org.apache.druid.guice.JsonConfigProvider.bind(JsonConfigProvider.java:152)
  while locating org.apache.druid.guice.ExtensionsConfig
    for the 1st parameter of org.apache.druid.guice.ExtensionsLoader.&lt;init&gt;(ExtensionsLoader.java:72)
  at org.apache.druid.guice.ExtensionsModule.configure(ExtensionsModule.java:37)
  while locating org.apache.druid.guice.ExtensionsLoader

1 error
        at com.google.inject.internal.InjectorImpl$2.get(InjectorImpl.java:1028)
        at com.google.inject.internal.InjectorImpl.getInstance(InjectorImpl.java:1054)
        at org.apache.druid.guice.ExtensionsLoader.instance(ExtensionsLoader.java:78)
        at org.apache.druid.cli.Main.main(Main.java:97)
Caused by: java.lang.IllegalArgumentException: Cannot deserialize instance of `java.util.LinkedHashSet&lt;java.lang.Object&gt;` out of VALUE_STRING token
 at [Source: UNKNOWN; line: -1, column: -1] (through reference chain: org.apache.druid.guice.ExtensionsConfig["loadList"])
        at com.fasterxml.jackson.databind.ObjectMapper._convert(ObjectMapper.java:3938)
        at com.fasterxml.jackson.databind.ObjectMapper.convertValue(ObjectMapper.java:3869)
        at org.apache.druid.guice.JsonConfigurator.configurate(JsonConfigurator.java:131)
        at org.apache.druid.guice.JsonConfigProvider.get(JsonConfigProvider.java:243)
        at org.apache.druid.guice.JsonConfigProvider.get(JsonConfigProvider.java:81)
        at com.google.inject.internal.ProviderInternalFactory.provision(ProviderInternalFactory.java:81)
        at com.google.inject.internal.InternalFactoryToInitializableAdapter.provision(InternalFactoryToInitializableAdapter.java:53)
        at com.google.inject.internal.ProviderInternalFactory.circularGet(ProviderInternalFactory.java:61)
        at com.google.inject.internal.InternalFactoryToInitializableAdapter.get(InternalFactoryToInitializableAdapter.java:45)
        at com.google.inject.internal.ProviderToInternalFactoryAdapter$1.call(ProviderToInternalFactoryAdapter.java:46)
        at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1092)
        at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:40)
        at com.google.inject.internal.SingletonScope$1.get(SingletonScope.java:194)
        at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:41)
        at com.google.inject.internal.InjectorImpl$2$1.call(InjectorImpl.java:1019)
        at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1092)
        at com.google.inject.internal.InjectorImpl$2.get(InjectorImpl.java:1015)
        at org.apache.druid.guice.SupplierProvider.get(SupplierProvider.java:52)
        at com.google.inject.internal.ProviderInternalFactory.provision(ProviderInternalFactory.java:81)
        at com.google.inject.internal.InternalFactoryToInitializableAdapter.provision(InternalFactoryToInitializableAdapter.java:53)
        at com.google.inject.internal.ProviderInternalFactory.circularGet(ProviderInternalFactory.java:61)
        at com.google.inject.internal.InternalFactoryToInitializableAdapter.get(InternalFactoryToInitializableAdapter.java:45)
        at com.google.inject.internal.SingleParameterInjector.inject(SingleParameterInjector.java:38)
        at com.google.inject.internal.SingleParameterInjector.getAll(SingleParameterInjector.java:62)
        at com.google.inject.internal.ConstructorInjector.provision(ConstructorInjector.java:110)
        at com.google.inject.internal.ConstructorInjector.construct(ConstructorInjector.java:90)
        at com.google.inject.internal.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:268)
        at com.google.inject.internal.ProviderToInternalFactoryAdapter$1.call(ProviderToInternalFactoryAdapter.java:46)
        at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1092)
        at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:40)
        at com.google.inject.internal.SingletonScope$1.get(SingletonScope.java:194)
        at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:41)
        at com.google.inject.internal.InjectorImpl$2$1.call(InjectorImpl.java:1019)
        at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1085)
        at com.google.inject.internal.InjectorImpl$2.get(InjectorImpl.java:1015)
        ... 3 more
Caused by: com.fasterxml.jackson.databind.exc.MismatchedInputException: Cannot deserialize instance of `java.util.LinkedHashSet&lt;java.lang.Object&gt;` out of VALUE_STRING token
 at [Source: UNKNOWN; line: -1, column: -1] (through reference chain: org.apache.druid.guice.ExtensionsConfig["loadList"])
        at com.fasterxml.jackson.databind.exc.MismatchedInputException.from(MismatchedInputException.java:59)
        at com.fasterxml.jackson.databind.DeserializationContext.reportInputMismatch(DeserializationContext.java:1445)
        at com.fasterxml.jackson.databind.DeserializationContext.handleUnexpectedToken(DeserializationContext.java:1219)
        at com.fasterxml.jackson.databind.DeserializationContext.handleUnexpectedToken(DeserializationContext.java:1129)
        at com.fasterxml.jackson.databind.deser.std.StringCollectionDeserializer.handleNonArray(StringCollectionDeserializer.java:274)
        at com.fasterxml.jackson.databind.deser.std.StringCollectionDeserializer.deserialize(StringCollectionDeserializer.java:183)
        at com.fasterxml.jackson.databind.deser.std.StringCollectionDeserializer.deserialize(StringCollectionDeserializer.java:173)
        at com.fasterxml.jackson.databind.deser.std.StringCollectionDeserializer.deserialize(StringCollectionDeserializer.java:21)
        at com.fasterxml.jackson.databind.deser.impl.FieldProperty.deserializeAndSet(FieldProperty.java:138)
        at com.fasterxml.jackson.databind.deser.BeanDeserializer.vanillaDeserialize(BeanDeserializer.java:288)
        at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserialize(BeanDeserializer.java:151)
        at com.fasterxml.jackson.databind.ObjectMapper._convert(ObjectMapper.java:3933)
        ... 37 more```

I'm referring to the error at the top of the log:
```Unable to parse value of property [druid.extensions.loadList] as a json object, using as is.```
It seems to be complaining about not being able to parse it so I would suspect a problem in the `druid.extensions.loadList` parameter syntax.

The only thing that caught my eye about the ingestion spec was
```"maxBytesInMemory": 0,```
Are you explicitly setting this?
Also, how many messages per hour are you expecting?
There is a benefit to lowering the "maxRowsInMemory" because when it writes to intermediate storage it indexes them into segment format which tends to improve query performance on the real-time data (indexed searches improve). Something like 100000 seems to be a good number. My understanding is that with a larger number you will improve ingestion performance, with a smaller one (not too small) it improves query performance.

Hello Sergio, sorry to answer you just now...
I'm not setting that `maxBytesInMemory` explicitly, I'll try to change it to some value.
About the `maxRowsInMemory`, I've left the default value, but I spect way below 5 Mil..

about the Peon process, is there any other place where I can see the logs from it? Is there a way to turn debugging logs on?

the task (peon) logs can be seen through the console in ingestion tab

is there any way to turn debugging log on? the task log shows the task starting at 2023-04-24T13:20:02,549 and shutting down at 2023-04-24T13:20:02,686, with no error message...

log.txt

in the `coordinator-overlorg.log` the error message is
```2023-04-24T13:19:00,280 WARN [IndexTaskClient-meiosdepagamento__db_claro_flex_app_payment-0] org.apache.druid.indexing.common.IndexTaskClient - submitRequest failed for [<http://8c21138ca0eb:8100/druid/worker/v1/chat/index_kafka_meiosdepagamento__db_claro_flex_app_payment_6752546731c6f07_cpfdjdpf/time/start>]
java.net.ConnectException: Connection refused (Connection refused)
        at java.net.PlainSocketImpl.socketConnect(Native Method) ~[?:1.8.0_362]
        at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[?:1.8.0_362]
        at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) ~[?:1.8.0_362]
        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) ~[?:1.8.0_362]
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[?:1.8.0_362]
        at java.net.Socket.connect(Socket.java:607) ~[?:1.8.0_362]
        at java.net.Socket.connect(Socket.java:556) ~[?:1.8.0_362]
        at java.net.Socket.&lt;init&gt;(Socket.java:452) ~[?:1.8.0_362]
        at java.net.Socket.&lt;init&gt;(Socket.java:229) ~[?:1.8.0_362]
        at org.apache.druid.indexing.common.IndexTaskClient.checkConnection(IndexTaskClient.java:208) ~[druid-indexing-service-25.0.0.jar:25.0.0]
        at org.apache.druid.indexing.common.IndexTaskClient.submitRequest(IndexTaskClient.java:351) ~[druid-indexing-service-25.0.0.jar:25.0.0]
        at org.apache.druid.indexing.common.IndexTaskClient.submitRequestWithEmptyContent(IndexTaskClient.java:219) ~[druid-indexing-service-25.0.0.jar:25.0.0]
        at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskClientSyncImpl.getStartTime(SeekableStreamIndexTaskClientSyncImpl.java:204) ~[druid-indexing-service-25.0.0.jar:25.0.0]
        at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskClientSyncImpl.lambda$getStartTimeAsync$3(SeekableStreamIndexTaskClientSyncImpl.java:382) ~[druid-indexing-service-25.0.0.jar:25.0.0]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_362]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_362]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_362]
        at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_362]
2023-04-24T13:19:00,285 WARN [KafkaSupervisor-meiosdepagamento__db_claro_flex_app_payment] org.apache.druid.indexing.seekablestream.supervisor.SeekableStreamSupervisor - Task [index_kafka_meiosdepagamento__db_claro_flex_app_payment_6752546731c6f07_cpfdjdpf] failed to return start time, killing task (java.lang.RuntimeException: java.net.ConnectException: Connection refused (Connection refused))
2023-04-24T13:19:00,290 INFO [IndexTaskClient-meiosdepagamento__db_claro_flex_app_payment-0] org.apache.druid.indexing.common.IndexTaskClient - submitRequest failed for [<http://8c21138ca0eb:8100/druid/worker/v1/chat/index_kafka_meiosdepagamento__db_claro_flex_app_payment_6752546731c6f07_cpfdjdpf/offsets/current>] (java.net.ConnectException: Connection refused (Connection refused))
2023-04-24T13:19:00,297 INFO [KafkaSupervisor-meiosdepagamento__db_claro_flex_app_payment] org.apache.druid.indexing.overlord.MetadataTaskStorage - Updating task index_kafka_meiosdepagamento__db_claro_flex_app_payment_6752546731c6f07_cpfdjdpf to status: TaskStatus{id=index_kafka_meiosdepagamento__db_claro_flex_app_payment_6752546731c6f07_cpfdjdpf, status=FAILED, duration=-1, errorMsg=Task [index_kafka_meiosdepagamento__db_claro_flex_app_payment_6752546731c6f07_cpfdjdpf] failed to re...}
2023-04-24T13:19:00,442 INFO [KafkaSupervisor-meiosdepagamento__db_claro_flex_app_payment] org.apache.druid.indexing.overlord.hrtr.HttpRemoteTaskRunner - Shutdown [index_kafka_meiosdepagamento__db_claro_flex_app_payment_6752546731c6f07_cpfdjdpf] because: [Task [index_kafka_meiosdepagamento__db_claro_flex_app_payment_6752546731c6f07_cpfdjdpf] failed to return start time, killing task]
2023-04-24T13:19:00,561 INFO [KafkaSupervisor-meiosdepagamento__db_claro_flex_app_payment] org.apache.druid.indexing.overlord.hrtr.WorkerHolder - Sent shutdown message to worker: 8c21138ca0eb:8091, status 200 OK, response: {"task":"index_kafka_meiosdepagamento__db_claro_flex_app_payment_6752546731c6f07_cpfdjdpf"}
2023-04-24T13:19:00,561 INFO [KafkaSupervisor-meiosdepagamento__db_claro_flex_app_payment] org.apache.druid.indexing.overlord.TaskLockbox - Removing task[index_kafka_meiosdepagamento__db_claro_flex_app_payment_6752546731c6f07_cpfdjdpf] from activeTasks
2023-04-24T13:19:00,582 INFO [KafkaSupervisor-meiosdepagamento__db_claro_flex_app_payment] org.apache.druid.indexing.seekablestream.supervisor.SeekableStreamSupervisor - [meiosdepagamento__db_claro_flex_app_payment] supervisor is running.
2023-04-24T13:19:00,650 WARN [KafkaSupervisor-meiosdepagamento__db_claro_flex_app_payment] org.apache.druid.indexing.seekablestream.supervisor.SeekableStreamSupervisor - Task [index_kafka_meiosdepagamento__db_claro_flex_app_payment_6752546731c6f07_cpfdjdpf] failed to return start time, killing task (org.apache.druid.indexing.common.IndexTaskClient$TaskNotRunnableException: Aborting request because task [index_kafka_meiosdepagamento__db_claro_flex_app_payment_6752546731c6f07_cpfdjdpf] is not runnable)```

you can see "Triggering JVM shutdown" in your task log. it means the task was shutdown by the overlord. which makes sense given the next logs you put up. I don't think that debug logs will help you here. In all likelihood, the port 8091 is open to outside but other ports such as 8100 are not. so you need to look into your network configuration

the dockerfile have 8100 to 8199 exposed and the docker run also

when the task starts, check if you can connect to 8100 or the port the task started at from the overlord container

it's hard to try that, becouse is too fast

2023-04-24T13:19:52,887 INFO [main] org.apache.druid.server.initialization.jetty.JettyServerModule - Creating http connector with port [8100]
2023-04-24T13:20:02,686 INFO [parent-monitor-0] org.apache.druid.indexing.worker.executor.ExecutorLifecycle - Triggering JVM shutdown.

Data server (historical + middlemanager) docker run command
```docker run -it --env-file ~/code/data-adapter-data-lake/druid/.env --name historical -p 8083:8083 -p 8091:8091 -p 8100-8199:8100-8199 --entrypoint /opt/druid/bin/start-cluster-data-server  --network druid-net -v /home/eggert/code/data-adapter-data-lake/druid/docker/conf:/opt/druid/conf druid```

hmm. your task starts at 13:19:52 but coordinator has issued kill command at 13:19:00

could be my machine resources the problem? is there any way to set a delay?

what does the middle manager say when was this task started?

middle.log

middlemanager log.... the task starts at line 172

hmm. that's the problem.
```2023-04-24T13:17:26,501 INFO [WorkerTaskManager-NoticeHandler] org.apache.druid.indexing.worker.WorkerTaskManager - Task[index_kafka_meiosdepagamento__db_claro_flex_app_payment_6752546731c6f07_cpfdjdpf] started.```
MM thinks the task started at 13:17:26 but the task started almost 2 minute later