Hi team. We have 16 partitions in a particular topic. We’re observing that one particular partition (partition 6) is not getting assigned to any realtime server. Due to this, there is no ingestion happening from that partition and the lag is increasing linearly. We rotated the realtime servers but that partition just isn’t getting assigned to any server (verified this form IDEASTATE. That partition doesn’t have any CONSUMING entry). How can we debug this further?

Are there any error logs on the controller related to partition 6? Cc: @Neha Pawar

Checking

Is your underlying stream Kafka or some other?

This is Kafka @Subbu Subramaniam

For some reason, your consuming partitions seem to be moving around hosts. Not sure why, we don't have any such segment allocation mechanism. Also, you seem to be creating a segment every 7 minutes. Probably not a good idea. What are the sizes of your segments, have you run the provisioner helping to size it appropriately? Lastly, your last segment in partition 6 was created on 20220119T1533Z. If yuo can please look in the logs around this time in the controller (info, warn. error, whatever) you may get a clue. Recreating the table may not help. My guess is that it may fall into the same trap. How many controllers do you have ? Have you enabled realtime segment correction background job? Did you restart your controller around the time mentioned above?

Hi thanks Subbu for the reply.

What are the sizes of your segments, have you run the provisioner helping to size it appropriately?

We have around 16k segments with an uncompressed size of 7.2T. So around 450M.

have you run the provisioner helping to size it appropriately?

@Tanmay Movva Can you answer this please?

Lastly, your last segment in partition 6 was created on 20220119T1533Z. If yuo can please look in the logs around this time in the controller (info, warn. error, whatever) you may get a clue.

We have three controllers. Here’s the most pertinent logs I see at that time: controller-0:

2022/01/19 15:33:18.991 WARN [ZKHelixManager] [pool-1-thread-5] Instance controller-0.controller-headless.pinot.svc.cluster.local_9000 is not leader of cluster pinot-prod due to current session 200040e14e70029 does not match leader session 200040e14e7001f",
-----------------------------------------------
2022/01/19 15:33:23.768 WARN [ConsumerConfig] [grizzly-http-server-1] The configuration 'realtime.segment.flush.threshold.rows' was supplied but isn't a known config.",
-----------------------------------------------
"2022/01/19 15:33:23.768 WARN [ConsumerConfig] [grizzly-http-server-1] The configuration 'stream.kafka.decoder.prop.schema.registry.url' was supplied but isn't a known config.",

controller-1: Surprisingly, there are no logs from this controller at that time. At least not present in our system. controller-2:

"2022/01/19 15:33:00.332 WARN [TopStateHandoffReportStage] [HelixController-pipeline-default-pinot-prod-(577ee9ef_DEFAULT)] Event 577ee9ef_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.",
-----------------------------------------------
"2022/01/19 15:33:01.506 WARN [TopStateHandoffReportStage] [HelixController-pipeline-default-pinot-prod-(a000d206_DEFAULT)] Event a000d206_DEFAULT : Cannot confirm top state missing start time. Use the current system time as the start time.",
-----------------------------------------------
"2022/01/19 15:33:23.709 WARN [ZkBaseDataAccessor] [HelixController-pipeline-task-pinot-prod-(761a1878_TASK)] Fail to read record for paths: {/pinot-prod/INSTANCES/Broker_broker-2.broker-headless.pinot.svc.cluster.local_8099/MESSAGES/c9a14adc-0d79-4e26-bfa6-ac61b6e86534=-101}",
-----------------------------------------------
"2022/01/19 15:33:27.281 WARN [ZkBaseDataAccessor] [HelixController-pipeline-default-pinot-prod-(19f6e886_DEFAULT)] Fail to read record for paths: {/pinot-prod/INSTANCES/Broker_broker-0.broker-headless.pinot.svc.cluster.local_8099/MESSAGES/113f8b3f-97da-48fc-becd-a5b5eb097306=-101}",

you defiintely need more servers.

@Subbu Subramaniam I just observed, we have two realtime servers that haven’t been consuming from any partitions. They’re just sitting idle with the following logs:

[0.000s][warning][gc] -Xloggc is deprecated. Will use -Xlog:gc:/opt/pinot/gc-pinot-server.log instead.
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/opt/pinot/lib/pinot-all-0.9.1-jar-with-dependencies.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/opt/pinot/plugins/pinot-input-format/pinot-parquet/pinot-parquet-0.9.1-shaded.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/opt/pinot/plugins/pinot-metrics/pinot-yammer/pinot-yammer-0.9.1-shaded.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/opt/pinot/plugins/pinot-metrics/pinot-dropwizard/pinot-dropwizard-0.9.1-shaded.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/opt/pinot/plugins/pinot-file-system/pinot-s3/pinot-s3-0.9.1-shaded.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/opt/pinot/plugins/pinot-environment/pinot-azure/pinot-azure-0.9.1-shaded.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See <http://www.slf4j.org/codes.html#multiple_bindings> for an explanation.
SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory]
WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance.
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by org.codehaus.groovy.reflection.CachedClass (file:/opt/pinot/lib/pinot-all-0.9.1-jar-with-dependencies.jar) to method java.lang.Object.finalize()
WARNING: Please consider reporting this to the maintainers of org.codehaus.groovy.reflection.CachedClass
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
2022/01/20 10:01:48.592 WARN [PinotMetricUtils] [Start a Pinot [SERVER]] More than one PinotMetricsFactory was found: [class org.apache.pinot.plugin.metrics.dropwizard.DropwizardMetricsFactory, class org.apache.pinot.plugin.metrics.yammer.YammerMetricsFactory]
2022/01/20 10:01:49.469 WARN [ParticipantHealthReportTask] [Start a Pinot [SERVER]] ParticipantHealthReportTimerTask already stopped
2022/01/20 10:01:49.696 WARN [ParticipantManager] [Start a Pinot [SERVER]] found another instance with same instanceName: Server_server-realtime-5.server-realtime-headless.pinot.svc.cluster.local_8098 in cluster pinot-prod
2022/01/20 10:02:24.844 WARN [CallbackHandler] [Start a Pinot [SERVER]] Callback handler received event in wrong order. Listener: org.apache.helix.messaging.handling.HelixTaskExecutor@791de65b, path: /pinot-prod/INSTANCES/Server_server-realtime-5.server-realtime-headless.pinot.svc.cluster.local_8098/MESSAGES, expected types: [CALLBACK, FINALIZE] but was INIT
Jan 20, 2022 10:02:27 AM org.glassfish.grizzly.http.server.NetworkListener start
INFO: Started listener bound to [0.0.0.0:8097]
Jan 20, 2022 10:02:27 AM org.glassfish.grizzly.http.server.HttpServer start
INFO: [HttpServer] Started.

Nothing after this! We have a total of 32 partitions so ideally they should be consuming as well? This might be a different issue, but looks like I’ll need to sort this out first before adding any realtime servers. Thanks 🙂

Thanks, please update on what you find in terms of how you ended up in that state.

make sure these servers are tagged correctly

@Subbu Subramaniam Apologies for the slow updates on this, I update this thread whenever I have new findings. We recently had some lag, and a bit of investigation revealed the following: 1. Node memory usage for Pinot was hitting ~ 80% of its limit. 2. Page faults around 50/s during peak. The trend follows our ingestion traffic trend closely (high traffic, high no. of faults, low traffic, low no. of faults). Is this a high number of faults? We are using off heap in MMAP mode for consuming segments (

pinot.server.instance.realtime.alloc.offheap=true

) 3. The CPU utilization was less than 50%. So I am going to be adding more memory to my pods. But I am trying to understand why you said that we definitely need more realtime servers. How did you reach that conclusion?

@Prashant Pandey there are multiple ways to skin this cat. Imagine P partitions of data coming in from your input stream onto N hosts. Since we have memory mapped the consuming segment data, each write into the segment is a dirty page for the OS to flush. Depending on your data characteristics, input rate, etc. this paging can increase. Of course, the same memory contends for queries coming in (so, your mem/paging will be very different if there are no queries). So, you can (1) Add more hosts so that we have less number of partitions streaming into any one host (2) Add more memory in each host so that more of the mmap pages are in memory, contending less with queries. No matter what, IIRC you were making segments every few minutes (if I am wrong, you can ignore this comment). Building segments takes up a lot of heap memory in the host. Also, your consumption is paused when you build segments, so you are serving stale data all the time. So, the best option is to build segments less often, which means accumulate more rows before you build segments, which leads to the arguments in the previous comment.

@Subbu Subramaniam Thank you so much for the detailed explanation, really informative. I have taken these inputs and am resizing our segments now.

Not sure what you mean by "Pinot recommends.." but there is no one size fits all. As you have realized, the equation has multiple variables, some of them controllable, some not. If you increase segment size, you need to have more memory to fit consuming segment. If you increase number of stream partitions, you can increase segment size, but then you will have more number of segments that can affect query performance. If you increase number of stream partitions and segment size to limit number of segments, you will either need more memory or more number of hosts.