Hi team, there's a unusual pattern in the latency ...
# troubleshooting
r
Hi team, there's a unusual pattern in the latency and server CPU for past 10 days, before that there was normal average latency going around 500ms to 1 second at most. But from 20th, there is a similar pattern that we can see in latency after 50th minute of every hour from 9:50 AM. There's a rise in latency to 10 seconds then coming down after 10 minutes and then going up again periodically every hour. The QPS is not changing or showing any variation as such within this period, checked at the query level as well no hard query is hitting. Controller JVM has increased but broker JVM decreased a bit. Is there anyway to find the root cause of this, we have gone through indexing, query checking, and disabled all the crons that were hitting. But still couldn't find anything wrong, is there any way that we can log all the events happening on pinot. If possible can we schedule a zoom call to understand the root cause and find the main problem with anyone of the Apache Pinot PMC. I've attached all the screenshots for reference. C.C. @Kavya
x
Check server level query latency metrics, if it also spikes then you could locate the issue coming from servers. Also check if the latency spikes associated with some GC events happening on pinot servers?
you table consuming latency increases might due to segment commit as well, I suppose your data ingestion rate also spike during day time? In that case you can try to add the offheap config for streaming table. https://docs.pinot.apache.org/operators/operating-pinot/tuning/realtime#controlling-memory-allocation
r
also why am I seeing deleted tables in here as well, does pinot stores any metadata even after deletion?
server level query latency is increasing but not as much as broker latency
Also check if the latency spikes associated with some GC events happening on pinot servers? -- How to check that?
x
what about p99 query latency
deleted table should be removed, but the metrics might be still there
I don't think you are still querying old deleted table ?
r
no no, I can't query a deleted table
x
then it's out of the equation
r
P99 is also behaving same
x
if p99 is 10s+ then it means the main issue is on the server side
if this is the realtime table ,have your tried the offheap config for it?
r
but from 20th we are facing this issue, older that it was very fine. No deployment has been sent regarding that
r
that I'll try once
x
then check if there is any change from gc logs
it might be due to the natural data growth on ingestion which triggers the query latency as the secondary effect
r
broker JVM are you telling to check, this off-heap config, does it make use of server JVM or broker JVM?
it might be due to the natural data growth on ingestion which triggers the query latency as the secondary effect - Yeah maybe, will try these fixes once and let you know
x
I don't think broker is the bottleneck
check servers
r
cool will check that.
g
You can also get some async-profiler/jfr dumps on the servers.
r
@Xiang Fu sharing the the values.yaml
Copy code
image:
  repository: <http://615177075440.dkr.ecr.ap-south-1.amazonaws.com/pinot|615177075440.dkr.ecr.ap-south-1.amazonaws.com/pinot>
  tag: 1.0.3
  pullPolicy: IfNotPresent

cluster:
  name: pinot-prod

# ----------------------------------------------------------------------------
# ZOOKEEPER: 3 replicas
# ----------------------------------------------------------------------------
zookeeper:
  name: pinot-zookeeper
  replicaCount: 3
  persistence:
    enabled:      true
    storageClass: gp3      # ← GP3 EBS
    size:         10Gi
  resources:
    requests:
      cpu:    100m
      memory: 256Mi
    limits:
      cpu:    300m
      memory: 512Mi

  port: 2181

# ----------------------------------------------------------------------------
# CONTROLLER: 2 replicas, internal LB
# ----------------------------------------------------------------------------
controller:
  name: pinot-controller
  replicaCount: 2
  startCommand: "StartController"
  # podManagementPolicy: Parallel
  resources:
    requests:
      cpu:    100m
      memory: 1Gi
    limits:
      cpu:    300m
      memory: 3Gi
  
  jvmOpts: "-javaagent:/opt/pinot/etc/jmx_prometheus_javaagent/jmx_prometheus_javaagent.jar=9010:/opt/pinot/etc/jmx_prometheus_javaagent/configs/pinot.yml -XX:ActiveProcessorCount=2 -Xms512M -Xmx2G -XX:+UseG1GC -XX:MaxGCPauseMillis=200 -Xlog:gc*:file=/opt/pinot/gc-pinot-controller.log -Djute.maxbuffer=4000000"
    
  # Persist controller metadata
  persistence:
    enabled:      true
    accessMode:   ReadWriteOnce
    storageClass: gp3
    size:         50Gi
    mountPath:    /var/pinot/controller/data

  service:
    name: controller
    annotations:
      <http://prometheus.io/scrape|prometheus.io/scrape>: "true"
      <http://prometheus.io/path|prometheus.io/path>: /metrics
      <http://prometheus.io/port|prometheus.io/port>: "9010"
    # labels:
    #   prometheus-monitor: "true"
    extraPorts:
      - name: controller-prom
        protocol: TCP
        containerPort: 9010
    
    
  podAnnotations:
    <http://prometheus.io/scrape|prometheus.io/scrape>: "true"
    <http://prometheus.io/path|prometheus.io/path>: /metrics
    <http://prometheus.io/port|prometheus.io/port>: "9010"

  # Expose via Kubernetes Ingress on port 9000
  # ingress:
  #   v1:
  #     enabled: true
  #     ingressClassName: nginx          # or your ingress controller
  #     annotations:
  #       <http://nginx.ingress.kubernetes.io/backend-protocol|nginx.ingress.kubernetes.io/backend-protocol>: "HTTP"
  #       <http://nginx.ingress.kubernetes.io/rewrite-target|nginx.ingress.kubernetes.io/rewrite-target>: /
  #     hosts: [<http://pinot-eks.sr-bi-internal.in|pinot-eks.sr-bi-internal.in>]
  #     path: /controller
  #     tls: []
  external:
    enabled: false

# ----------------------------------------------------------------------------
# BROKER: 2 replicas, internal LB
# ----------------------------------------------------------------------------
broker:
  name: pinot-broker
  startCommand: "StartBroker"
  # podManagementPolicy: Parallel
  replicaCount: 2

  resources:
    requests:
      cpu:    200m
      memory: 1Gi
    limits:
      cpu:    500m
      memory: 3Gi

  jvmOpts: "-javaagent:/opt/pinot/etc/jmx_prometheus_javaagent/jmx_prometheus_javaagent.jar=9020:/opt/pinot/etc/jmx_prometheus_javaagent/configs/pinot.yml -XX:ActiveProcessorCount=2 -Xms512M -Xmx2G -XX:+UseG1GC -XX:MaxGCPauseMillis=200 -Xlog:gc*:file=/opt/pinot/gc-pinot-broker.log -Djute.maxbuffer=4000000"

  service:
    name: broker
    # type: LoadBalancer
    annotations:
      # <http://service.beta.kubernetes.io/aws-load-balancer-internal|service.beta.kubernetes.io/aws-load-balancer-internal>: "true"
      <http://prometheus.io/scrape|prometheus.io/scrape>: "true"
      <http://prometheus.io/path|prometheus.io/path>: /metrics
      <http://prometheus.io/port|prometheus.io/port>: "9020"
    # labels:
    #   prometheus-monitor: "true"
    extraPorts:
      - name: broker-prom
        protocol: TCP
        containerPort: 9020
    
  podAnnotations:
    <http://prometheus.io/scrape|prometheus.io/scrape>: "true"
    <http://prometheus.io/path|prometheus.io/path>: /metrics
    <http://prometheus.io/port|prometheus.io/port>: "9020"

  # Expose via Kubernetes Ingress on port 8099
  # ingress:
  #   v1:
  #     enabled: true
  #     ingressClassName: nginx          # or your ingress controller
  #     annotations:
  #       <http://nginx.ingress.kubernetes.io/backend-protocol|nginx.ingress.kubernetes.io/backend-protocol>: "HTTP"
  #       <http://nginx.ingress.kubernetes.io/use-regex|nginx.ingress.kubernetes.io/use-regex>: "true"
  #       <http://nginx.ingress.kubernetes.io/rewrite-target|nginx.ingress.kubernetes.io/rewrite-target>: /$2
  #     hosts: [<http://pinot-eks.sr-bi-internal.in|pinot-eks.sr-bi-internal.in>]
  #     path: /broker(/|$)(.*)
  #     pathType: ImplementationSpecific
  #     tls: []
  external:
    enabled: false


# ----------------------------------------------------------------------------
# PINOT SERVER: 2 replicas, each with 100 Gi gp3 PVC
# ----------------------------------------------------------------------------
server:
  name: pinot-server
  startCommand: "StartServer"
  # podManagementPolicy: Parallel
  replicaCount: 3
  
  resources:
    requests:
      cpu:    2000m    # 2 vCPU
      memory: 5Gi
    limits:
      cpu:    3500m    # 4 vCPU
      memory: 10Gi

  persistence:
    enabled: true
    accessMode: ReadWriteOnce
    size: 100G
    mountPath: /var/pinot/server/data
    storageClass: gp3
  
  jvmOpts: "-javaagent:/opt/pinot/etc/jmx_prometheus_javaagent/jmx_prometheus_javaagent.jar=9030:/opt/pinot/etc/jmx_prometheus_javaagent/configs/pinot.yml -Xms4G -Xmx8G -XX:+UseG1GC -XX:MaxGCPauseMillis=200 -Xlog:gc*:file=/opt/pinot/gc-pinot-server.log -Djute.maxbuffer=4000000"

  service:
    name: server
    # type: LoadBalancer
    annotations:
      # <http://service.beta.kubernetes.io/aws-load-balancer-internal|service.beta.kubernetes.io/aws-load-balancer-internal>: "true"
      <http://prometheus.io/scrape|prometheus.io/scrape>: "true"
      <http://prometheus.io/path|prometheus.io/path>: /metrics
      <http://prometheus.io/port|prometheus.io/port>: "9030"
    # labels:
    #   prometheus-monitor: "true"
    extraPorts:
      - name: server-prom
        protocol: TCP
        containerPort: 9030
    
  podAnnotations:
    <http://prometheus.io/scrape|prometheus.io/scrape>: "true"
    <http://prometheus.io/path|prometheus.io/path>: /metrics
    <http://prometheus.io/port|prometheus.io/port>: "9030"


# ----------------------------------------------------------------------------
# MINION: 1 replica (for background tasks / retention, compaction, etc.)
# ----------------------------------------------------------------------------
minion:
  enabled: true           # run the minion pod
  name: pinot-minion
  startCommand: "StartMinion"
  # podManagementPolicy: Parallel
  replicaCount: 1         # scale up if you have heavy compaction/merge workloads

  resources:
    requests:
      cpu:    100m
      memory: 512Mi
    limits:
      cpu:    200m
      memory: 1Gi

  jvmOpts: "-javaagent:/opt/pinot/etc/jmx_prometheus_javaagent/jmx_prometheus_javaagent.jar=8008:/opt/pinot/etc/jmx_prometheus_javaagent/configs/pinot.yml -XX:ActiveProcessorCount=2 -Xms256M -Xmx1G -XX:+UseG1GC -XX:MaxGCPauseMillis=200 -Xlog:gc*:file=/opt/pinot/gc-pinot-minion.log -Djute.maxbuffer=4000000"
also, if off-heap server side is an issue, why there is an increase of query latency upto 10 seconds but server query processing time is at most 1-2 seconds? Also please review this values.yaml any suggestions regarding this issue?
FYI:- Also in this cluster we are not using deepstore here's the table configs for realtime and offline: REALTIME:
Copy code
{
  "REALTIME": {
    "tableName": "shipmentMerged_final_REALTIME",
    "tableType": "REALTIME",
    "segmentsConfig": {
      "replication": "2",
      "retentionTimeUnit": "DAYS",
      "retentionTimeValue": "4",
      "timeType": "DAYS",
      "timeColumnName": "s_created_at",
      "minimizeDataMovement": false
    },
    "tenants": {
      "broker": "DefaultTenant",
      "server": "DefaultTenant"
    },
    "tableIndexConfig": {
      "invertedIndexColumns": [
        "o_customer_city",
        "o_customer_pincode",
        "o_customer_state",
        "s_company_id",
        "s_courier",
        "o_shipping_method",
        "o_payment_method",
        "s_status",
        "s_sr_courier_id",
        "o_status",
        "ar_zone",
        "o_state",
        "ms_status",
        "o_customer_country_code",
        "cnf_courier",
        "sa_city",
        "sa_state",
        "sa_pincode",
        "co_mode",
        "co_id",
        "o_is_international",
        "o_is_return",
        "o_state"
      ],
      "noDictionaryColumns": [
        "s_etd",
        "s_shipped_date",
        "a_awb_code",
        "s_order_id",
        "s_id",
        "a_id",
        "o_id",
        "a_shipment_id",
        "s_delivered_date",
        "s_awb",
        "s_pickup_scheduled_date",
        "a_applied_weight_amount_double",
        "o_total_double",
        "ts_ms_source_kafka",
        "o_net_total_double",
        "a_charge_weight_amount_double",
        "s_rto_delivered_date",
        "ar_awb_id",
        "am_picked_up_date",
        "am_ofd1",
        "s_total_double",
        "ts_ms_merged_kafka",
        "tier_id"
      ],
      "aggregateMetrics": false,
      "enableDefaultStarTree": false,
      "nullHandlingEnabled": true,
      "bloomFilterColumns": [
        "s_company_id",
        "s_sr_courier_id"
      ],
      "rangeIndexColumns": [
        "s_created_at",
        "o_created_at",
        "s_awb_assign_date",
        "s_rto_initiated_date"
      ],
      "sortedColumn": [
        "s_company_id"
      ],
      "varLengthDictionaryColumns": [
        "o_customer_state",
        "ar_zone",
        "s_courier",
        "o_customer_pincode",
        "o_payment_method",
        "o_shipping_method",
        "o_customer_city"
      ],
      "rangeIndexVersion": 2,
      "optimizeDictionaryForMetrics": false,
      "optimizeDictionary": false,
      "enableDynamicStarTreeCreation": false,
      "columnMajorSegmentBuilderEnabled": true,
      "optimizeDictionaryType": false,
      "noDictionarySizeRatioThreshold": 0.85,
      "autoGeneratedInvertedIndex": false,
      "createInvertedIndexDuringSegmentGeneration": true,
      "loadMode": "MMAP"
    },
    "metadata": {
      "customConfigs": {}
    },
    "routing": {
      "instanceSelectorType": "strictReplicaGroup"
    },
    "upsertConfig": {
      "enableDeletedKeysCompactionConsistency": false,
      "enablePreload": false,
      "deletedKeysTTL": 0,
      "enableSnapshot": false,
      "newSegmentTrackingTimeMs": 10000,
      "mode": "FULL",
      "consistencyMode": "SYNC",
      "comparisonColumns": [
        "s_updated_at"
      ],
      "metadataTTL": 0,
      "deleteRecordColumn": "is_deleted",
      "dropOutOfOrderRecord": false,
      "hashFunction": "NONE",
      "defaultPartialUpsertStrategy": "OVERWRITE",
      "upsertViewRefreshIntervalMs": 3000,
      "allowPartialUpsertConsumptionDuringCommit": false
    },
    "ingestionConfig": {
      "streamIngestionConfig": {
        "streamConfigMaps": [
          {
            "streamType": "kafka",
            "stream.kafka.consumer.type": "lowlevel",
            "stream.kafka.decoder.prop.format": "AVRO",
            "stream.kafka.consumer.group.id": "shipmentMerged-consumer-group",
            "stream.kafka.decoder.prop.schema.registry.rest.url": "<http://internal-adfbe53cf874c419b80ef29810ee56b7-1168949678.ap-south-1.elb.amazonaws.com:8081>",
            "stream.kafka.topic.name": "pinot_d0_d2_realtime",
            "stream.kafka.consumer.factory.class.name": "org.apache.pinot.plugin.stream.kafka20.KafkaConsumerFactory",
            "stream.kafka.decoder.class.name": "org.apache.pinot.plugin.inputformat.avro.confluent.KafkaConfluentSchemaRegistryAvroMessageDecoder",
            "stream.kafka.broker.list": "<http://internal-a01a7420dce764739aecf132fdd316d8-1810051101.ap-south-1.elb.amazonaws.com:9094|internal-a01a7420dce764739aecf132fdd316d8-1810051101.ap-south-1.elb.amazonaws.com:9094>",
            "stream.kafka.schema.registry.url": "<http://internal-adfbe53cf874c419b80ef29810ee56b7-1168949678.ap-south-1.elb.amazonaws.com:8081>",
            "realtime.segment.flush.threshold.time": "24h",
            "realtime.segment.flush.threshold.segment.size": "150M",
            "stream.kafka.consumer.prop.auto.offset.reset": "smallest"
          }
        ],
        "columnMajorSegmentBuilderEnabled": true,
        "trackFilteredMessageOffsets": false
      },
      "transformConfigs": [
        {
          "columnName": "is_deleted",
          "transformFunction": "compareFields(op, 'd')"
        },
        {
          "columnName": "s_total_double",
          "transformFunction": "bytesToDouble(s_total, 10, 2)"
        },
        {
          "columnName": "o_net_total_double",
          "transformFunction": "bytesToDouble(o_net_total, 10, 2)"
        },
        {
          "columnName": "o_total_double",
          "transformFunction": "bytesToDouble(o_total, 10, 2)"
        },
        {
          "columnName": "a_applied_weight_amount_double",
          "transformFunction": "bytesToDouble(a_applied_weight_amount, 10, 2)"
        },
        {
          "columnName": "a_charge_weight_amount_double",
          "transformFunction": "bytesToDouble(a_charge_weight_amount, 10, 2)"
        }
      ],
      "continueOnError": false,
      "rowTimeValueCheck": false,
      "segmentTimeValueCheck": true
    },
    "isDimTable": false
  }
}
OFFLINE:
Copy code
{
  "OFFLINE": {
    "tableName": "shipmentMerged_final_OFFLINE",
    "tableType": "OFFLINE",
    "segmentsConfig": {
      "replication": "2",
      "retentionTimeUnit": "DAYS",
      "retentionTimeValue": "120",
      "timeType": "DAYS",
      "timeColumnName": "s_created_at",
      "minimizeDataMovement": false
    },
    "tenants": {
      "broker": "DefaultTenant",
      "server": "DefaultTenant"
    },
    "tableIndexConfig": {
      "invertedIndexColumns": [
        "o_customer_city",
        "o_customer_pincode",
        "o_customer_state",
        "s_company_id",
        "s_courier",
        "o_shipping_method",
        "o_payment_method",
        "s_status",
        "s_sr_courier_id",
        "o_status",
        "ar_zone",
        "o_state",
        "ms_status",
        "o_customer_country_code",
        "cnf_courier",
        "sa_city",
        "sa_state",
        "sa_pincode",
        "co_mode",
        "co_id",
        "o_is_international",
        "o_is_return",
        "o_state"
      ],
      "noDictionaryColumns": [
        "s_etd",
        "s_shipped_date",
        "a_awb_code",
        "s_order_id",
        "s_updated_at",
        "s_id",
        "a_id",
        "o_id",
        "a_shipment_id",
        "s_delivered_date",
        "s_awb",
        "s_pickup_scheduled_date",
        "a_applied_weight_amount_double",
        "o_total_double",
        "ts_ms_source_kafka",
        "o_net_total_double",
        "a_charge_weight_amount_double",
        "s_rto_delivered_date",
        "ar_awb_id",
        "am_picked_up_date",
        "am_ofd1",
        "s_total_double",
        "ts_ms_merged_kafka",
        "tier_id"
      ],
      "aggregateMetrics": false,
      "starTreeIndexConfigs": [
        {
          "dimensionsSplitOrder": [
            "o_shipping_method",
            "o_payment_method",
            "s_courier",
            "s_status",
            "s_company_id"
          ],
          "functionColumnPairs": [
            "SUM__o_net_total_double",
            "SUM__o_total_double",
            "SUM__a_applied_weight_amount_double",
            "SUM__a_charge_weight_amount_double",
            "COUNT__*"
          ],
          "maxLeafRecords": 10000
        }
      ],
      "enableDefaultStarTree": false,
      "nullHandlingEnabled": false,
      "bloomFilterColumns": [
        "s_company_id",
        "s_sr_courier_id"
      ],
      "rangeIndexColumns": [
        "s_created_at",
        "o_created_at",
        "s_awb_assign_date",
        "s_rto_initiated_date"
      ],
      "sortedColumn": [
        "s_company_id"
      ],
      "varLengthDictionaryColumns": [
        "o_customer_state",
        "ar_zone",
        "s_courier",
        "o_customer_pincode",
        "o_payment_method",
        "o_shipping_method",
        "o_customer_city"
      ],
      "rangeIndexVersion": 2,
      "optimizeDictionaryForMetrics": false,
      "optimizeDictionary": false,
      "enableDynamicStarTreeCreation": false,
      "columnMajorSegmentBuilderEnabled": true,
      "optimizeDictionaryType": false,
      "noDictionarySizeRatioThreshold": 0.85,
      "autoGeneratedInvertedIndex": false,
      "createInvertedIndexDuringSegmentGeneration": false,
      "loadMode": "MMAP"
    },
    "metadata": {
      "customConfigs": {
        "cleanup.policy": "segmentAge",
        "delete.retention.hours": "720"
      }
    },
    "ingestionConfig": {
      "batchIngestionConfig": {
        "batchConfigMaps": [
          {
            "inputDirURI": "<s3://sr-datapipeline/data-platform/pinot/offline_data/>",
            "inputFormat": "parquet",
            "outputDirURI": "<s3://sr-datapipeline/data-platform/pinot/segments/>",
            "input.fs.className": "org.apache.pinot.plugin.filesystem.S3PinotFS",
            "input.fs.prop.region": "ap-south-1"
          }
        ],
        "segmentIngestionType": "APPEND",
        "segmentIngestionFrequency": "DAILY",
        "consistentDataPush": false
      },
      "continueOnError": false,
      "rowTimeValueCheck": false,
      "segmentTimeValueCheck": true
    },
    "isDimTable": false
  }
}
I can see some off-heap usage right now as well without turning on the the off-heap config , any idea why?
x
I would suggest to change k8s request and limit to be the same value. And xms=xmx = 50% of the pod memory
e.g. for server:
Copy code
resources:
    requests:
      cpu:    3500m    # 2 vCPU
      memory: 10Gi
    limits:
      cpu:    3500m    # 4 vCPU
      memory: 10Gi

  persistence:
    enabled: true
    accessMode: ReadWriteOnce
    size: 100G
    mountPath: /var/pinot/server/data
    storageClass: gp3
  
  jvmOpts: "-javaagent:/opt/pinot/etc/jmx_prometheus_javaagent/jmx_prometheus_javaagent.jar=9030:/opt/pinot/etc/jmx_prometheus_javaagent/configs/pinot.yml -Xms5G -Xmx5G -XX:+UseG1GC -XX:MaxGCPauseMillis=200 -Xlog:gc*:file=/opt/pinot/gc-pinot-server.log -Djute.maxbuffer=4000000"
jvm default directMemory is same as heap xmx
offheap usage is expected as pinot will memory map data from disk