2017-07-18 02:03:15 +00:00
|
|
|
package batchconsumer
|
|
|
|
|
|
|
|
|
|
import (
|
2020-11-11 02:40:34 +00:00
|
|
|
"bytes"
|
|
|
|
|
"compress/zlib"
|
2017-07-18 02:03:15 +00:00
|
|
|
"context"
|
|
|
|
|
"encoding/base64"
|
|
|
|
|
"fmt"
|
2020-11-11 02:40:34 +00:00
|
|
|
"io/ioutil"
|
2017-07-18 02:03:15 +00:00
|
|
|
"math/big"
|
|
|
|
|
|
|
|
|
|
"golang.org/x/time/rate"
|
|
|
|
|
kv "gopkg.in/Clever/kayvee-go.v6/logger"
|
|
|
|
|
|
2017-08-07 03:05:41 +00:00
|
|
|
"github.com/Clever/amazon-kinesis-client-go/batchconsumer/stats"
|
2017-07-18 02:03:15 +00:00
|
|
|
"github.com/Clever/amazon-kinesis-client-go/kcl"
|
|
|
|
|
"github.com/Clever/amazon-kinesis-client-go/splitter"
|
|
|
|
|
)
|
|
|
|
|
|
2017-07-18 19:19:40 +00:00
|
|
|
type batchedWriter struct {
|
2017-11-02 21:49:13 +00:00
|
|
|
config Config
|
|
|
|
|
sender Sender
|
|
|
|
|
failedLogsFile kv.KayveeLogger
|
2017-07-18 02:03:15 +00:00
|
|
|
|
2017-07-21 01:35:54 +00:00
|
|
|
shardID string
|
|
|
|
|
|
2017-08-04 09:36:42 +00:00
|
|
|
chkpntManager *checkpointManager
|
|
|
|
|
batcherManager *batcherManager
|
2017-07-18 02:03:15 +00:00
|
|
|
|
|
|
|
|
// Limits the number of records read from the stream
|
|
|
|
|
rateLimiter *rate.Limiter
|
|
|
|
|
|
2017-08-02 19:45:23 +00:00
|
|
|
lastProcessedSeq kcl.SequencePair
|
2017-07-18 02:03:15 +00:00
|
|
|
}
|
|
|
|
|
|
2017-11-03 17:48:50 +00:00
|
|
|
func NewBatchedWriter(config Config, sender Sender, failedLogsFile kv.KayveeLogger) *batchedWriter {
|
2017-07-21 01:35:54 +00:00
|
|
|
return &batchedWriter{
|
2017-11-02 21:49:13 +00:00
|
|
|
config: config,
|
|
|
|
|
sender: sender,
|
|
|
|
|
failedLogsFile: failedLogsFile,
|
2017-07-21 01:35:54 +00:00
|
|
|
|
|
|
|
|
rateLimiter: rate.NewLimiter(rate.Limit(config.ReadRateLimit), config.ReadBurstLimit),
|
|
|
|
|
}
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
func (b *batchedWriter) Initialize(shardID string, checkpointer kcl.Checkpointer) error {
|
2017-07-18 02:03:15 +00:00
|
|
|
b.shardID = shardID
|
|
|
|
|
|
2017-08-10 20:11:24 +00:00
|
|
|
bmConfig := batcherManagerConfig{
|
|
|
|
|
BatchCount: b.config.BatchCount,
|
|
|
|
|
BatchSize: b.config.BatchSize,
|
|
|
|
|
BatchInterval: b.config.BatchInterval,
|
|
|
|
|
}
|
|
|
|
|
|
2018-08-09 23:43:30 +00:00
|
|
|
b.sender.Initialize(shardID)
|
|
|
|
|
|
2017-11-03 17:48:50 +00:00
|
|
|
b.chkpntManager = newCheckpointManager(checkpointer, b.config.CheckpointFreq)
|
|
|
|
|
b.batcherManager = newBatcherManager(b.sender, b.chkpntManager, bmConfig, b.failedLogsFile)
|
2017-07-18 02:03:15 +00:00
|
|
|
|
|
|
|
|
return nil
|
|
|
|
|
}
|
|
|
|
|
|
2017-07-18 19:19:40 +00:00
|
|
|
func (b *batchedWriter) splitMessageIfNecessary(record []byte) ([][]byte, error) {
|
2020-11-11 02:40:34 +00:00
|
|
|
// We handle three types of records:
|
2020-11-11 17:39:51 +00:00
|
|
|
// - records emitted from CWLogs Subscription (which are gzip compressed)
|
2020-11-11 02:40:34 +00:00
|
|
|
// - uncompressed records emitted from KPL
|
|
|
|
|
// - zlib compressed records (e.g. as compressed and emitted by Kinesis plugin for Fluent Bit)
|
|
|
|
|
if splitter.IsGzipped(record) {
|
|
|
|
|
// Process a batch of messages from a CWLogs Subscription
|
|
|
|
|
return splitter.GetMessagesFromGzippedInput(record)
|
2017-07-18 02:03:15 +00:00
|
|
|
}
|
|
|
|
|
|
2020-11-11 02:40:34 +00:00
|
|
|
// Try to read it as a zlib-compressed record
|
|
|
|
|
// zlib.NewReader checks for a zlib header and returns an error if not found
|
|
|
|
|
zlibReader, err := zlib.NewReader(bytes.NewReader(record))
|
|
|
|
|
if err == nil {
|
|
|
|
|
unzlibRecord, err := ioutil.ReadAll(zlibReader)
|
|
|
|
|
if err != nil {
|
|
|
|
|
return nil, fmt.Errorf("reading zlib-compressed record: %v", err)
|
|
|
|
|
}
|
|
|
|
|
return [][]byte{unzlibRecord}, nil
|
|
|
|
|
}
|
|
|
|
|
// Process a single message, from KPL
|
|
|
|
|
return [][]byte{record}, nil
|
|
|
|
|
|
2017-07-18 02:03:15 +00:00
|
|
|
}
|
|
|
|
|
|
2017-07-18 19:19:40 +00:00
|
|
|
func (b *batchedWriter) ProcessRecords(records []kcl.Record) error {
|
2017-08-02 19:45:23 +00:00
|
|
|
var pair kcl.SequencePair
|
2017-07-21 01:35:54 +00:00
|
|
|
prevPair := b.lastProcessedSeq
|
2017-07-18 02:03:15 +00:00
|
|
|
|
|
|
|
|
for _, record := range records {
|
|
|
|
|
// Wait until rate limiter permits one more record to be processed
|
|
|
|
|
b.rateLimiter.Wait(context.Background())
|
|
|
|
|
|
|
|
|
|
seq := new(big.Int)
|
|
|
|
|
if _, ok := seq.SetString(record.SequenceNumber, 10); !ok { // Validating sequence
|
|
|
|
|
return fmt.Errorf("could not parse sequence number '%s'", record.SequenceNumber)
|
|
|
|
|
}
|
|
|
|
|
|
2017-08-10 21:28:13 +00:00
|
|
|
pair = kcl.SequencePair{Sequence: seq, SubSequence: record.SubSequenceNumber}
|
2017-08-10 20:16:41 +00:00
|
|
|
if prevPair.IsNil() { // Handles on-start edge case where b.lastProcessSeq is empty
|
2017-07-21 01:35:54 +00:00
|
|
|
prevPair = pair
|
|
|
|
|
}
|
2017-07-18 02:03:15 +00:00
|
|
|
|
|
|
|
|
data, err := base64.StdEncoding.DecodeString(record.Data)
|
|
|
|
|
if err != nil {
|
|
|
|
|
return err
|
|
|
|
|
}
|
|
|
|
|
|
2017-07-21 01:35:54 +00:00
|
|
|
messages, err := b.splitMessageIfNecessary(data)
|
2017-07-18 02:03:15 +00:00
|
|
|
if err != nil {
|
|
|
|
|
return err
|
|
|
|
|
}
|
2017-08-03 21:22:52 +00:00
|
|
|
wasPairIgnored := true
|
2017-07-21 01:35:54 +00:00
|
|
|
for _, rawmsg := range messages {
|
|
|
|
|
msg, tags, err := b.sender.ProcessMessage(rawmsg)
|
|
|
|
|
|
2017-07-19 00:21:31 +00:00
|
|
|
if err == ErrMessageIgnored {
|
2017-07-18 02:03:15 +00:00
|
|
|
continue // Skip message
|
|
|
|
|
} else if err != nil {
|
2017-08-07 03:05:41 +00:00
|
|
|
stats.Counter("unknown-error", 1)
|
2017-11-03 17:48:50 +00:00
|
|
|
lg.ErrorD("process-message", kv.M{"msg": err.Error(), "rawmsg": string(rawmsg)})
|
2017-07-21 01:35:54 +00:00
|
|
|
continue // Don't stop processing messages because of one bad message
|
2017-07-18 02:03:15 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
if len(tags) == 0 {
|
2017-08-07 03:05:41 +00:00
|
|
|
stats.Counter("no-tags", 1)
|
2017-11-03 17:48:50 +00:00
|
|
|
lg.ErrorD("no-tags", kv.M{"rawmsg": string(rawmsg)})
|
2017-07-21 01:35:54 +00:00
|
|
|
return fmt.Errorf("No tags provided by consumer for log: %s", string(rawmsg))
|
2017-07-18 02:03:15 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
for _, tag := range tags {
|
2017-07-21 01:35:54 +00:00
|
|
|
if tag == "" {
|
2017-08-07 03:05:41 +00:00
|
|
|
stats.Counter("blank-tag", 1)
|
2017-11-03 17:48:50 +00:00
|
|
|
lg.ErrorD("blank-tag", kv.M{"rawmsg": string(rawmsg)})
|
2017-07-21 01:35:54 +00:00
|
|
|
return fmt.Errorf("Blank tag provided by consumer for log: %s", string(rawmsg))
|
2017-07-18 02:03:15 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
// Use second to last sequence number to ensure we don't checkpoint a message before
|
|
|
|
|
// it's been sent. When batches are sent, conceptually we first find the smallest
|
|
|
|
|
// sequence number amount all the batch (let's call it A). We then checkpoint at
|
|
|
|
|
// the A-1 sequence number.
|
2017-08-04 09:36:42 +00:00
|
|
|
b.batcherManager.BatchMessage(tag, msg, prevPair)
|
2017-08-03 21:22:52 +00:00
|
|
|
wasPairIgnored = false
|
2017-07-18 02:03:15 +00:00
|
|
|
}
|
|
|
|
|
}
|
|
|
|
|
|
2017-07-21 01:35:54 +00:00
|
|
|
prevPair = pair
|
2017-08-03 21:22:52 +00:00
|
|
|
if wasPairIgnored {
|
2017-08-04 09:36:42 +00:00
|
|
|
b.batcherManager.LatestIgnored(pair)
|
2017-08-03 21:22:52 +00:00
|
|
|
}
|
2017-08-04 09:36:42 +00:00
|
|
|
b.batcherManager.LatestProcessed(pair)
|
2017-08-07 03:05:41 +00:00
|
|
|
|
|
|
|
|
stats.Counter("processed-messages", len(messages))
|
2017-07-18 02:03:15 +00:00
|
|
|
}
|
2017-07-21 01:35:54 +00:00
|
|
|
b.lastProcessedSeq = pair
|
2017-07-18 02:03:15 +00:00
|
|
|
|
2017-07-21 01:35:54 +00:00
|
|
|
return nil
|
2017-07-18 02:03:15 +00:00
|
|
|
}
|
|
|
|
|
|
2017-07-18 19:19:40 +00:00
|
|
|
func (b *batchedWriter) Shutdown(reason string) error {
|
2017-07-18 02:03:15 +00:00
|
|
|
if reason == "TERMINATE" {
|
2017-11-03 17:48:50 +00:00
|
|
|
lg.InfoD("terminate-signal", kv.M{"shard-id": b.shardID})
|
2017-07-18 02:03:15 +00:00
|
|
|
} else {
|
2017-11-03 17:48:50 +00:00
|
|
|
lg.ErrorD("shutdown-failover", kv.M{"shard-id": b.shardID, "reason": reason})
|
2017-07-18 02:03:15 +00:00
|
|
|
}
|
2017-08-04 09:36:42 +00:00
|
|
|
|
2017-08-08 19:09:31 +00:00
|
|
|
done := b.batcherManager.Shutdown()
|
|
|
|
|
<-done
|
2017-08-04 09:36:42 +00:00
|
|
|
|
2017-07-18 02:03:15 +00:00
|
|
|
return nil
|
|
|
|
|
}
|