Monitoring & Consumer Lag
ไอเดียในหนึ่งประโยค
หัวข้อที่มีชื่อว่า “ไอเดียในหนึ่งประโยค”Kafka มี metric หลายร้อยตัวผ่าน JMX แต่สัญญาณระดับ application ที่สำคัญที่สุดตัวเดียวคือ consumer lag — ช่องว่างระหว่าง log-end-offset ของ partition กับ offset ที่ consumer group commit ไว้ — และ lag ไม่ใช่ สิ่งเดียวกับ latency ซึ่งบทนี้พิสูจน์ทั้งฝั่ง server และฝั่ง app
พิสูจน์: LAG จริง ลดจาก 700 เหลือ 0
หัวข้อที่มีชื่อว่า “พิสูจน์: LAG จริง ลดจาก 700 เหลือ 0”produce 1,000 record เข้า topic ใหม่ แล้ว consume สองรอบ — 300 record หยุด แล้ว consume ที่เหลืออีก 700 — โดยรัน kafka-consumer-groups.sh --describe คั่นกลาง
# Self-contained: creates its own topic, produces, consumes partially, then fully./opt/kafka/bin/kafka-topics.sh --bootstrap-server "$BOOTSTRAP" \ --create --topic lesson-lag-demo --partitions 1 --replication-factor 1
/opt/kafka/bin/kafka-producer-perf-test.sh --topic lesson-lag-demo \ --num-records 1000 --record-size 100 --throughput -1 \ --producer-props bootstrap.servers="$BOOTSTRAP" > /dev/null 2>&1
/opt/kafka/bin/kafka-console-consumer.sh --bootstrap-server "$BOOTSTRAP" \ --topic lesson-lag-demo --group lesson-lag-group \ --from-beginning --max-messages 300 --timeout-ms 15000 > /dev/null 2>&1
/opt/kafka/bin/kafka-consumer-groups.sh --bootstrap-server "$BOOTSTRAP" \ --describe --group lesson-lag-groupGROUP TOPIC PARTITION CURRENT-OFFSET LOG-END-OFFSET LAG CONSUMER-ID HOST CLIENT-IDlesson-lag-group lesson-lag-demo 0 300 1000 700 - - -LAG=700 จริง — เท่ากับ 1000 - 300 พอดี consume ส่วนที่เหลือ 700 record แล้ว describe อีกครั้ง
/opt/kafka/bin/kafka-console-consumer.sh --bootstrap-server "$BOOTSTRAP" \ --topic lesson-lag-demo --group lesson-lag-group \ --max-messages 700 --timeout-ms 15000 > /dev/null 2>&1
/opt/kafka/bin/kafka-consumer-groups.sh --bootstrap-server "$BOOTSTRAP" \ --describe --group lesson-lag-groupGROUP TOPIC PARTITION CURRENT-OFFSET LOG-END-OFFSET LAG CONSUMER-ID HOST CLIENT-IDlesson-lag-group lesson-lag-demo 0 1000 1000 0 - - -LAG=0 — consumer group ตามทันจริง LAG คือ LOG-END-OFFSET - CURRENT-OFFSET เสมอ ดูเป็น trend ไม่ใช่ค่าเดียว: คงที่หรือลดลงคือสุขภาพดี ไต่ขึ้นเรื่อย ๆ คือสัญญาณเตือนแรกสุดว่า consumer overload ค้าง หรือ crash
flowchart LR prod["Producer appends records"] --> leo["Log-end-offset (newest)"] cons["Consumer group commits"] --> cur["Committed offset (processed)"] leo -->|"difference"| lag["LAG = log-end-offset - committed offset"] cur --> lag
Lag ไม่ใช่ latency
หัวข้อที่มีชื่อว่า “Lag ไม่ใช่ latency”การดู RequestMetrics,name=TotalTimeMs,request=Produce (พิสูจน์ด้านล่างผ่าน JMX) บน broker ว่างของบทนี้แสดง percentile ทุกตัวเป็น 0.0 — broker ตอบทุก request ทันที ตัวเลขนั้นไม่บอกอะไรเลยว่า consumer group ตามทันหรือไม่: broker อาจมี request latency แค่หลัก millisecond เดียว ในขณะที่ consumer group ยังมี LAG เป็นล้าน record ได้ ถ้า group นั้นแค่ดึงข้อมูลไม่ทัน ถูก pause หรือ crash ในทางกลับกัน consumer อาจแสดง LAG=0 ในขณะที่ request latency สูงขึ้น — มันแค่ตามทันแบบเฉียดฉิว ทั้งสองเป็นสัญญาณอิสระจากกัน: latency วัดว่า request หนึ่งใช้เวลานานแค่ไหน; lag วัดว่าการประมวลผลของทั้ง group ตกหลังไปแค่ไหน สะสมมาตามเวลา
metric ฝั่ง broker ผ่าน JMX อ่านจริง
หัวข้อที่มีชื่อว่า “metric ฝั่ง broker ผ่าน JMX อ่านจริง”broker ของ Kafka เผยแพร่ metric ผ่าน JMX kafka-run-class.sh org.apache.kafka.tools.JmxTool (ยืนยันเป็นชื่อ class จริงใน 4.3.1 ผ่าน --help) อ่านมันได้โดยตรง ไม่ต้องมี agent ภายนอก
/opt/kafka/bin/kafka-run-class.sh org.apache.kafka.tools.JmxTool --help | head -5Dump JMX values to standard output.Option Description------ -------------attributes <String: name> The list of attributes to include inอ่านสองตัวที่ non-negotiable จริง ๆ กับ broker ที่เปิด JMX ของบทนี้เอง
$ kafka-run-class.sh org.apache.kafka.tools.JmxTool \ --jmx-url service:jmx:rmi:///jndi/rmi://localhost:39094/jmxrmi \ --object-name 'kafka.server:type=ReplicaManager,name=UnderReplicatedPartitions' \ --object-name 'kafka.network:type=SocketServer,name=NetworkProcessorAvgIdlePercent' \ --one-time true --report-format propertieskafka.server:type=ReplicaManager,name=UnderReplicatedPartitions:Value=0kafka.network:type=SocketServer,name=NetworkProcessorAvgIdlePercent:Value=0.38543167517469595UnderReplicatedPartitions— partition ที่ ISR เล็กกว่า replication factor setup RF=1 broker เดียวของบทนี้อ่านได้0จริง (ไม่มีอะไรให้ under-replicate); cluster หลาย broker ที่สุขภาพดีก็ควรอ่าน0ตลอดเวลาเช่นกัน อะไรก็ตามที่สูงกว่าศูนย์นานเกินชั่วครู่หนึ่งแปลว่า replica ตามหลังอยู่หรือ broker ล่ม — durability กำลังเสี่ยงอยู่ตอนนี้NetworkProcessorAvgIdlePercent— สัดส่วนเวลาที่ network thread ว่าง ค่าจริง0.385ที่นี่ (Mac เครื่องนี้ load แบบ single-partition ที่ว่างเกือบทั้งหมด) ใกล้1.0คือ headroom ที่ดี ค่าที่ไต่ลงไปทาง0แปลว่า network thread อิ่มตัว request เริ่มต่อคิวก่อนจะถูก parse ด้วยซ้ำ
สัดส่วน idle ของ request-handler thread pool output จริง (เป็น Yammer-metrics meter จึงมี field Rate/Count แทนที่จะเป็น Value เดียว)
kafka.server:type=KafkaRequestHandlerPool,name=RequestHandlerAvgIdlePercent:OneMinuteRate=0.9708645122119944kafka.server:type=KafkaRequestHandlerPool,name=RequestHandlerAvgIdlePercent:FiveMinuteRate=0.9669659596065399RequestHandlerAvgIdlePercent ใกล้ 1.0 (97% ว่างที่นี่) แปลว่า request handler thread มีกำลังสำรองเหลือเฟือ ไต่ลงไปทาง 0 แปลว่าทุก handler thread ยุ่งตลอดเวลา — broker กำลัง CPU-bound บนการประมวลผล request และ produce/fetch latency กำลังจะไต่ขึ้น
Prometheus JMX exporter
หัวข้อที่มีชื่อว่า “Prometheus JMX exporter”การอ่าน MBean ทีละตัวด้วย JmxTool ไม่ scale ไปถึง dashboard และ alerting ทางมาตรฐานคือ Prometheus JMX exporter รันเป็น Java agent ใน JVM เดียวกัน (มีเอกสารที่ prometheus.github.io/jmx_exporter/deployment/java-agent ยืนยัน syntax แล้ว)
# KAFKA_OPTS is a shell/launch env var, not a server.properties key --# shown as a transcript, not a checked properties fence.KAFKA_OPTS=-javaagent:/opt/jmx_prometheus_javaagent-1.6.0.jar=9404:/opt/kafka-jmx-exporter.ymlflag -javaagent:<jar>=<PORT>:<EXPORTER_YAML> ตัวเดียวนั้นเปิด HTTP endpoint ที่ 0.0.0.0:9404 เสิร์ฟทุก MBean ที่ config ไว้ในรูปแบบ Prometheus text exposition ไม่ต้องมี JMX/RMI network hop แยกเลย (agent รันข้างใน JVM ของ broker เอง) บทนี้ไม่ได้ตั้ง Prometheus + Grafana เต็มรูปแบบ — config key และ syntax อ้างอิงตรงจากเอกสารของ exporter เอง ไม่ได้รันครบวงจร
Lag ฝั่ง app จาก client ที่ไม่ใช่ JVM: instrumentation event ของ KafkaJS
หัวข้อที่มีชื่อว่า “Lag ฝั่ง app จาก client ที่ไม่ใช่ JVM: instrumentation event ของ KafkaJS”KafkaJS consumer เผย JMX ไม่ได้ — ไม่มี JVM สัญญาณ lag จริงของมันคือ instrumentation event consumer.events.END_BATCH_PROCESS (ชื่อ event ยืนยันตรงจาก source ของ [email protected] ที่ติดตั้งไว้ src/consumer/instrumentationEvents.js: HEARTBEAT, COMMIT_OFFSETS, GROUP_JOIN, FETCH, FETCH_START, START_BATCH_PROCESS, END_BATCH_PROCESS, CRASH, REBALANCING และอื่น ๆ) payload จริงของมัน (ยืนยันจาก src/consumer/runner.js) มี offsetLag, offsetLagLow, batchSize, firstOffset, lastOffset, และ duration
// lag-instrumentation.ts -- run directly against this lesson's own scratch// broker (kafka-ops, port 39092), not the shared harness probe: it shares a// persistent groupId/topic across runs, which the harness's own probe// broker accumulates state on across the whole course's test history.import { Kafka } from 'kafkajs';
const brokers = [(process.env.KAFKA_BROKERS ?? 'localhost:9092')];const prefix = process.env.TOPIC_PREFIX ?? '';const topic = `${prefix}lag-instrumentation-demo`;const kafka = new Kafka({ clientId: 'lag-instrumentation', brokers });
// Self-contained: produce a small backlog first, THEN subscribe and consume// it, so this fence proves the real event shape without depending on any// pre-existing topic state.const admin = kafka.admin();await admin.connect();await admin.createTopics({ topics: [{ topic, numPartitions: 1, replicationFactor: 1 }] });await admin.disconnect();
const producer = kafka.producer();await producer.connect();await producer.send({ topic, messages: Array.from({ length: 20 }, (_, i) => ({ value: `record-${i}` })),});await producer.disconnect();
const consumer = kafka.consumer({ groupId: `${prefix}lag-instrumentation-group` });consumer.on(consumer.events.END_BATCH_PROCESS, ({ payload }) => { console.log(`batchSize=${payload.batchSize} offsetLag=${payload.offsetLag} offsetLagLow=${payload.offsetLagLow}`);});
await consumer.connect();await consumer.subscribe({ topic, fromBeginning: true });
let processed = 0;await consumer.run({ eachMessage: async () => { processed++; if (processed >= 20) { await consumer.disconnect(); process.exit(0); } },});บทนี้ยังรัน event เดียวกัน payload offsetLag/offsetLagLow กับ backlog ที่มีอยู่ก่อนแล้วขนาดใหญ่กว่ามาก (1,000 record นั่งอยู่ใน topic ก่อนที่ consumer group จะเข้าร่วมด้วยซ้ำ) บน scratch broker ของตัวเอง เพื่อดูว่าจะเกิดอะไรขึ้นเมื่อ backlog ทั้งหมดตกอยู่ใน fetch batch เดียว แทนที่จะเป็นหลาย batch เล็ก ๆ — output จริง จับความละเอียดอ่อนที่เข้าใจผิดง่ายของสอง field นี้ได้
END_BATCH_PROCESS batchSize=1000 offsetLag=0 offsetLagLow=999offsetLag (คำนวณจาก offset ล่าสุด ใน batch) อ่านได้ 0 — ถูกต้องในทางเทคนิค record ล่าสุดของ batch นี้คือ record ใหม่สุดที่มีตอน fetch แต่ offsetLagLow (คำนวณจาก offset แรก ใน batch) อ่านได้ 999 — มี record ที่ยังไม่ได้ประมวลผลจริง 999 ตัวอยู่ข้างหน้า message แรก ที่ batch นี้เริ่มประมวลผล dashboard ที่ผูกกับ offsetLag อย่างเดียวจะรายงาน “ไม่มี lag” ตลอดเวลาที่ batch 1,000 record นี้ถูกประมวลผลโดย eachMessage ซึ่งทำให้เข้าใจผิดถ้าการประมวลผลนั้นใช้เวลาจริง ๆ การบังคับให้ batch เล็กลง (backlog 500 record จำกัด maxBytesPerPartition ให้ต่ำ) ทำให้สอง field เดียวกันหดตัวลงพร้อมกัน ทีละ batch ตามที่คาดไว้เป๊ะ
END_BATCH_PROCESS batchSize=3 offsetLag=497 offsetLagLow=499END_BATCH_PROCESS batchSize=3 offsetLag=494 offsetLagLow=496END_BATCH_PROCESS batchSize=3 offsetLag=491 offsetLagLow=493[... continues shrinking by 3 every batch ...]END_BATCH_PROCESS batchSize=3 offsetLag=410 offsetLagLow=412อ่านโค้ดที่ AI เขียน
หัวข้อที่มีชื่อว่า “อ่านโค้ดที่ AI เขียน”🐛 หา bug ในโค้ดนี้
// AI comment: "Track consumer lag so we can alert if it grows"import { Kafka } from 'kafkajs';
const kafka = new Kafka({ clientId: 'lag-alerter', brokers: ['localhost:9092'] });const consumer = kafka.consumer({ groupId: 'orders-processor' });
consumer.on(consumer.events.END_BATCH_PROCESS, ({ payload }) => {if (payload.offsetLag > 1000) { console.error('ALERT: consumer is falling behind!', payload.offsetLag);}});เฉลย
ดูสมเหตุสมผล — subscribe event END_BATCH_PROCESS ที่มีเอกสารจริง แล้ว alert บน field ที่มีเอกสารจริง bug ที่พิสูจน์ด้านบนกับ broker จริง: offsetLag คำนวณจาก offset ล่าสุด ในแต่ละ batch ที่ fetch มา ดังนั้นทุกครั้งที่ consumer ตามหลังจริง ๆ และ Kafka ยื่น batch catch-up ก้อนใหญ่ให้ (run ของบทนี้เอง: 1,000 record ที่ backlog อยู่ใน batch เดียว) offsetLag จะอ่านได้ 0 ตลอดเวลาที่ batch ใหญ่นั้นกำลังถูกประมวลผล — ตรงกับจังหวะที่ alert จริงควรจะดังที่สุดเป๊ะ วิธีแก้คือ alert บน offsetLagLow แทน (หรือเพิ่มเข้าไปด้วย) ซึ่งคำนวณจาก offset แรก ใน batch และพิสูจน์ด้านบนว่าแสดง 999 ถูกต้องใน scenario เดียวกันเป๊ะที่ offsetLag รายงานเป็น 0 script monitoring ที่สร้างจาก offsetLag อย่างเดียวจะรายงาน lag ต่ำกว่าความจริงได้มากถึงขนาด batch เต็มก้อน แย่ที่สุดตรงเป๊ะตอนที่ consumer ตามหลังไกลที่สุดและกำลัง fetch batch catch-up ที่ใหญ่ที่สุดของมัน
Mental Model
หัวข้อที่มีชื่อว่า “Mental Model”มอง monitoring เป็นเครื่องมืออิสระสองชิ้นที่ชี้ไปที่สองสิ่งต่างกัน JMX / broker metric คือหูฟังแพทย์บน broker เอง — มันสุขภาพดีตอนนี้ ขณะนี้หรือไม่ (thread ว่าง, สถานะ replication, request latency) Consumer lag คือมาตรวัดระยะทางของการเดินทางของ group หนึ่ง — มันตกหลังไปแค่ไหน สะสมมาตลอดเวลาที่มันดิ้นรน broker อาจสุขภาพดีเป๊ะตาม JMX metric ทุกตัว ในขณะที่ lag ของ consumer group เฉพาะเจาะจงไต่ขึ้นไปหลักล้าน เพราะ broker ไม่เคยเป็นคอขวดเลย — logic ประมวลผลของ consumer เองต่างหาก alert ทั้งสองอย่าง แต่มันตอบคำถามคนละข้อ และไม่มีตัวไหนแทนที่อีกตัวได้
Trade-offs
หัวข้อที่มีชื่อว่า “Trade-offs”JmxToolอ่านแบบครั้งเดียวเทียบกับ Prometheus JMX exporter —JmxToolไม่ต้อง setup อะไรเลยและเหมาะกับการเช็กจริงแบบเร็ว (พิสูจน์ด้านบน ไม่ต้องมี process เพิ่ม) แต่ไม่ scale ไปถึง dashboard, ประวัติ, หรือ alerting rule; exporter คือคำตอบด้าน operation จริง แลกกับ agent flag เพิ่มอีกตัวและไฟล์ YAML mapping ที่ต้องดูแลoffsetLagเทียบกับoffsetLagLow—offsetLagคิดแบบง่าย ๆ ได้ถูกกว่า (“lag หลัง batch นี้”) และเก็บไว้เพื่อ backward compatibility;offsetLagLowพิสูจน์ด้านบนว่าต่างกันมากบน batch ใหญ่ เป็นตัวเลขที่ซื่อสัตย์กว่าสำหรับ alerting แลกกับการตั้งชื่อที่เข้าใจยากกว่าเล็กน้อยบน dashboard- การ poll
kafka-consumer-groups.sh --describeเทียบกับ instrumentation ฝั่ง app — CLI คือความจริงพื้นฐานและใช้ได้กับ consumer ภาษาไหนก็ได้ แต่ให้แค่ snapshot ณ จุดเวลาที่คุณบังเอิญรันมันเท่านั้น; instrumentation event (KafkaJS) หรือ JMX (Java client) ให้การมองเห็นต่อเนื่องแบบ real-time ข้างในตัว app เอง แลกกับการผูกกับ client library เฉพาะตัว
ความเข้าใจผิดที่พบบ่อย
หัวข้อที่มีชื่อว่า “ความเข้าใจผิดที่พบบ่อย”- “request latency ต่ำแปลว่า consumer ตามทัน” ไม่ — พิสูจน์ด้านบน: broker ของบทนี้มี produce latency
0.0ทุก percentile ในขณะที่ consumer group แบกรับLAGจริงที่ไม่ใช่ศูนย์พร้อมกัน — มันเป็นการวัดอิสระของคนละสิ่ง - “
offsetLagกับoffsetLagLowเป็น field ซ้ำซ้อนที่ตรงกันเสมอ” ไม่ — พิสูจน์ด้านบน: batch เดียว 1,000 record ให้offsetLag=0และoffsetLagLow=999พร้อมกัน ต่างกันเท่ากับขนาด batch ทั้งก้อน ไม่ใช่ความคลาดเคลื่อนจากการปัดเศษ - “KafkaJS app เผย JMX metric เดียวกับ Java Kafka client ได้” ไม่ — พิสูจน์ด้านบน (และตามข้อเท็จจริงง่าย ๆ): ไม่มี JVM ใน process ของ KafkaJS เลยไม่มี JMX เลย สิ่งที่ใกล้เคียงที่สุดคือ field payload ของ
consumer.events.END_BATCH_PROCESSเอง - “
UnderReplicatedPartitionsเป็น0บน cluster ทดสอบ broker เดียวพิสูจน์ว่า metric ทำงาน” ทำให้เข้าใจผิดบางส่วน — พิสูจน์ด้านบนว่ามันอ่าน0จริง แต่เพราะไม่มีอะไรให้ under-replicate บน RF=1; metric นี้จะมีความหมายจริงก็ต่อเมื่อ cluster มีมากกว่าหนึ่ง broker และมีอะไรที่ตกหลังได้จริง ๆ