You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@kafka.apache.org by "Travis Bischel (Jira)" <ji...@apache.org> on 2023/10/20 00:26:00 UTC
[jira] [Created] (KAFKA-15656) Frequent INVALID_RECORD on Kafka 3.6
Travis Bischel created KAFKA-15656:
--------------------------------------
Summary: Frequent INVALID_RECORD on Kafka 3.6
Key: KAFKA-15656
URL: https://issues.apache.org/jira/browse/KAFKA-15656
Project: Kafka
Issue Type: Bug
Components: producer
Affects Versions: 3.6.0
Reporter: Travis Bischel
Attachments: invalid_record.log
Using this docker-compose.yml:
{noformat}
version: "3.7"
services:
kafka:
image: bitnami/kafka:latest
network_mode: host
environment:
KAFKA_ENABLE_KRAFT: yes
KAFKA_CFG_PROCESS_ROLES: controller,broker
KAFKA_CFG_CONTROLLER_LISTENER_NAMES: CONTROLLER
KAFKA_CFG_LISTENERS: PLAINTEXT://:9092,CONTROLLER://:9093
KAFKA_CFG_LISTENER_SECURITY_PROTOCOL_MAP: CONTROLLER:PLAINTEXT,PLAINTEXT:PLAINTEXT
KAFKA_CFG_CONTROLLER_QUORUM_VOTERS: 1@127.0.0.1:9093
# Set this to "PLAINTEXT://127.0.0.1:9092" if you want to run this container on localhost via Docker
KAFKA_CFG_ADVERTISED_LISTENERS: PLAINTEXT://localhost:9092
KAFKA_CFG_NODE_ID: 1
ALLOW_PLAINTEXT_LISTENER: yes
KAFKA_KRAFT_CLUSTER_ID: XkpGZQ27R3eTl3OdTm2LYA # 16 byte base64-encoded UUID{noformat}
And running franz-go integration tests with KGO_TEST_RF=1, I consistently receive INVALID_RECORD errors.
Looking at the container logs, I see these problematic log lines:
{noformat}
2023-10-19 23:33:47,942] ERROR [ReplicaManager broker=1] Error processing append operation on partition 0cf2f3faaafd3f906ea848b684b04833ca162bcd19ecae2cab36767a54f248c7-0 (kafka.server.ReplicaManager)
org.apache.kafka.common.InvalidRecordException: Invalid negative header key size -25
[2023-10-19 23:33:47,942] ERROR [ReplicaManager broker=1] Error processing append operation on partition 0cf2f3faaafd3f906ea848b684b04833ca162bcd19ecae2cab36767a54f248c7-6 (kafka.server.ReplicaManager)
org.apache.kafka.common.InvalidRecordException: Reached end of input stream before skipping all bytes. Remaining bytes:94
[2023-10-19 23:33:47,942] ERROR [ReplicaManager broker=1] Error processing append operation on partition 0cf2f3faaafd3f906ea848b684b04833ca162bcd19ecae2cab36767a54f248c7-1 (kafka.server.ReplicaManager)
org.apache.kafka.common.InvalidRecordException: Found invalid number of record headers -26
[2023-10-19 23:33:47,948] ERROR [ReplicaManager broker=1] Error processing append operation on partition 0cf2f3faaafd3f906ea848b684b04833ca162bcd19ecae2cab36767a54f248c7-6 (kafka.server.ReplicaManager)
org.apache.kafka.common.InvalidRecordException: Found invalid number of record headers -27
[2023-10-19 23:33:47,950] ERROR [ReplicaManager broker=1] Error processing append operation on partition 0cf2f3faaafd3f906ea848b684b04833ca162bcd19ecae2cab36767a54f248c7-22 (kafka.server.ReplicaManager)
org.apache.kafka.common.InvalidRecordException: Invalid negative header key size -25
[2023-10-19 23:33:47,947] ERROR [ReplicaManager broker=1] Error processing append operation on partition c63b6e30987317fad18815effb8d432b6df677d2ab56cf6da517bb93fa49b74b-25 (kafka.server.ReplicaManager)
org.apache.kafka.common.InvalidRecordException: Found invalid number of record headers -50
[2023-10-19 23:33:47,959] ERROR [ReplicaManager broker=1] Error processing append operation on partition c63b6e30987317fad18815effb8d432b6df677d2ab56cf6da517bb93fa49b74b-25 (kafka.server.ReplicaManager)
{noformat}
I modified franz-go with a diff to print the request that was written to the wire once this error occurs. Attached is a v9 produce request. I deserialized it locally and am not seeing the corrupt data that Kafka is printing. It's possible there is a bug in the client, but again, these tests have never received this error pre-Kafka 3.6. It _looks like_ there is either corruption when processing the incoming data, or there is some problematic race condition in the broker - I'm not sure which.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)