search

housepower / clickhouse_sinker

Easily load data from kafka to ClickHouse
https://housepower.github.io/clickhouse_sinker
Apache License 2.0
515 stars 118 forks source link

index out of range #133

Closed josepowera closed 2 years ago

josepowera commented 2 years ago

we are running on git master version.

{"level":"debug","ts":"2021-11-10T19:43:55.203Z","msg":"got a message(topic ssprtbwinsraw, partition 1, offset 1815122436) while the ring is full, waiting...","task":"csv_ssp_ssprtbwins_raw"}
{"level":"debug","ts":"2021-11-10T19:44:01.500Z","msg":"going to flush a batch for topic ssprtbwinsraw patittion 0, offset [1815154410,1815159242), messages 4832, parse errors: 0","task":"csv_ssp_ssprtbwins_raw"}
{"level":"info","ts":"2021-11-10T19:44:09.501Z","msg":"topic ssprtbwinsraw partition 1 became idle","task":"csv_ssp_ssprtbwins_raw"}
{"level":"debug","ts":"2021-11-10T19:44:09.503Z","msg":"going to flush a batch for topic ssprtbwinsraw patittion 0, offset [1815159242,1815165028), messages 5786, parse errors: 0","task":"csv_ssp_ssprtbwins_raw"}
panic: runtime error: index out of range [4612] with length 0

goroutine 92 [running]:
github.com/housepower/clickhouse_sinker/task.(*Ring).PutElem(0xc0003d65a0, 0xc009d34300, 0xc0057a1590, 0x0)
    /app/task/ring.go:59 +0x56d
github.com/housepower/clickhouse_sinker/task.(*Service).put.func1()
    /app/task/task.go:328 +0x3c8
github.com/housepower/clickhouse_sinker/util.(*WorkerPool).wokerFunc(0xc00014e340)
    /app/util/workerpool.go:59 +0xae
created by github.com/housepower/clickhouse_sinker/util.(*WorkerPool).start
    /app/util/workerpool.go:79 +0x45

config file:

{
  "clickhouse": {
    "hosts": [
      [
        "clickhouse-pv-simple-19000.test-clickhouse-operator.svc.cluster.local"
      ]
    ],
    "port": 19000,
    "db": "test5ssp",
    "username": "",
    "password": "",
    "retryTimes": 0
  },
  "kafka": {
    "brokers": "kafkaoss-kafka-bootstrap.kafka.svc.cluster.local:9092",
    "version": "2.2.1"
  },
  "task": {
    "name": "csv_ssp_ssprtbwins_raw",
    "kafka": "kfk1",
    "topic": "ssprtbwinsraw",
    "earliest": true,
    "consumerGroup": "chrawctb6",
    "parser": "csv",
    "csvFormat": [
      "tenantid",
      "dspid",
      "dspseatid",
      "adprocesstype",
      "adzoneid",
      "campaignid",
      "creativeid",
      "geocountry3",
      "dealid",
      "currency",
      "requestid",
      "eventtime",
      "auctionid",
      "impressionid",
      "bidid",
      "mediacost",
      "bidprice",
      "quantity",
      "publisherid",
      "siteid",
      "crtype",
      "mediatype"
    ],
    "delimiter": ",",
    "clickhouse": "ch1ssp",
    "tableName": "ssprtbwins_raw_raw",
    "@desc_of_autoSchema": "auto schema will auto fetch the schema from clickhouse",
    "autoSchema": true,
    "@desc_of_exclude_columns": "this columns will be excluded by insert SQL",
    "excludeColumns": [
      "eventDate",
      "eventTimeStamp"
    ],
    "bufferSize": 10000,
    "flushInterval": 5
  },
  "logLevel": "debug"
}
yuzhichang commented 2 years ago

Please try v2.1.0 or the latest master f82c1e7a3b74432f866c391e282d6e93778b2b8b

josepowera commented 2 years ago

Yes, we run v2.1.0

{"level":"info","ts":"2021-11-10T20:07:19.561Z","msg":"version v2.1.0-2-gd4578fa-dirty, commit d4578fa37ccd635cff7706ea018d90c414cb4f29, date 2021-11-10T19:31:30+00:00, builtBy root@80f8c4cdfedf"}

We also updated kafka to 2.8 and updated kafka.version in task json config files.

However the problem with "index out of range" remains. It also seems that this happens only when chsinker is under pressure ("when it was stopped and we got bigger backlog of unprocessed kafka->clickhouse") events.

It seems that based on number "index out of range [xxx]" is related to config "bufferSize":16384

{"level":"debug","ts":"2021-11-12T12:10:17.612Z","msg":"got a message(topic dsprtbbidsraw, partition 0, offset 1894474288) while the ring is full, wake-up","task":"csv_dsp_dsprtbbids_raw"}
{"level":"debug","ts":"2021-11-12T12:10:18.800Z","msg":"going to flush a batch for topic dsprtbbidsraw patittion 0, offset [1894447590,1894449152), messages 1562, parse errors: 0","task":"csv_dsp_dsprtbbids_raw"}
{"level":"debug","ts":"2021-11-12T12:10:18.817Z","msg":"going to flush a batch for topic dsprtbbidsraw patittion 1, offset [1894728235,1894735222), messages 6987, parse errors: 0","task":"csv_dsp_dsprtbbids_raw"}
{"level":"debug","ts":"2021-11-12T12:10:21.111Z","msg":"got a message(topic dsprtbbidsraw, partition 0, offset 1894481920) while the ring is full, waiting...","task":"csv_dsp_dsprtbbids_raw"}
{"level":"debug","ts":"2021-11-12T12:10:23.188Z","msg":"got a message(topic dsprtbbidsraw, partition 1, offset 1894761003) while the ring is full, wake-up","task":"csv_dsp_dsprtbbids_raw"}
{"level":"debug","ts":"2021-11-12T12:10:24.712Z","msg":"got a message(topic dsprtbbidsraw, partition 1, offset 1894767990) while the ring is full, waiting...","task":"csv_dsp_dsprtbbids_raw"}
{"level":"debug","ts":"2021-11-12T12:10:25.905Z","msg":"going to flush a batch for topic dsprtbbidsraw patittion 0, offset [1894449152,1894457585), messages 8433, parse errors: 0","task":"csv_dsp_dsprtbbids_raw"}
{"level":"debug","ts":"2021-11-12T12:10:26.000Z","msg":"got a message(topic dsprtbbidsraw, partition 0, offset 1894481920) while the ring is full, wake-up","task":"csv_dsp_dsprtbbids_raw"}
{"level":"debug","ts":"2021-11-12T12:10:27.303Z","msg":"going to flush a batch for topic dsprtbbidsraw patittion 1, offset [1894735222,1894744064), messages 8842, parse errors: 0","task":"csv_dsp_dsprtbbids_raw"}
{"level":"debug","ts":"2021-11-12T12:10:27.703Z","msg":"got a message(topic dsprtbbidsraw, partition 0, offset 1894490353) while the ring is full, waiting...","task":"csv_dsp_dsprtbbids_raw"}
{"level":"debug","ts":"2021-11-12T12:10:28.101Z","msg":"going to flush a batch for topic dsprtbbidsraw patittion 0, offset [1894457585,1894465536), messages 7951, parse errors: 0","task":"csv_dsp_dsprtbbids_raw"}
{"level":"debug","ts":"2021-11-12T12:10:30.714Z","msg":"got a message(topic dsprtbbidsraw, partition 1, offset 1894767990) while the ring is full, wake-up","task":"csv_dsp_dsprtbbids_raw"}
{"level":"debug","ts":"2021-11-12T12:10:30.716Z","msg":"going to flush a batch for topic dsprtbbidsraw patittion 1, offset [1894744064,1894744067), messages 3, parse errors: 0","task":"csv_dsp_dsprtbbids_raw"}
{"level":"debug","ts":"2021-11-12T12:10:32.821Z","msg":"got a message(topic dsprtbbidsraw, partition 0, offset 1894490353) while the ring is full, wake-up","task":"csv_dsp_dsprtbbids_raw"}
{"level":"debug","ts":"2021-11-12T12:10:34.203Z","msg":"got a message(topic dsprtbbidsraw, partition 0, offset 1894498304) while the ring is full, waiting...","task":"csv_dsp_dsprtbbids_raw"}
{"level":"debug","ts":"2021-11-12T12:10:38.900Z","msg":"going to flush a batch for topic dsprtbbidsraw patittion 1, offset [1894744067,1894748719), messages 4652, parse errors: 0","task":"csv_dsp_dsprtbbids_raw"}
{"level":"info","ts":"2021-11-12T12:10:45.078Z","msg":"topic dsprtbbidsraw partition 0 became idle","task":"csv_dsp_dsprtbbids_raw"}
panic: runtime error: index out of range [16385] with length 0

goroutine 85 [running]:
github.com/housepower/clickhouse_sinker/task.(*Ring).PutElem(0xc0001ae1b0, 0xc00d200300, 0xc00690dae8, 0x0)
    /app/task/ring.go:59 +0x56d
github.com/housepower/clickhouse_sinker/task.(*Service).put.func1()
    /app/task/task.go:328 +0x3c8
github.com/housepower/clickhouse_sinker/util.(*WorkerPool).wokerFunc(0xc000230080)
    /app/util/workerpool.go:59 +0xae
created by github.com/housepower/clickhouse_sinker/util.(*WorkerPool).start
    /app/util/workerpool.go:79 +0x45
yuzhichang commented 2 years ago

Please provide the full log of clickhouse_sinker. What's the avg size of each kafka message? Please try master tip 20f3a850ed1369e2992dd7ef88a69fdd396d16f4.

josepowera commented 2 years ago

Tried with 20f3a85. Looks OK for now. Will reopen if anything in production reoocures.