Skip to content

Commit 16547a1

Browse files
authored
Add a user-facing log when processing large txn (#4500)
Add a user-facing log when a large txn result in a PullRecord sync interval to get extended. Logged once per sync_interval, but throttled at 1 minute in case customer has a very short sync intervals that makes the log excessively noisy. Fixes: DBI-681
1 parent 633a773 commit 16547a1

4 files changed

Lines changed: 22 additions & 5 deletions

File tree

flow/activities/flowable.go

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -583,7 +583,7 @@ func (a *FlowableActivity) GetQRepPartitions(ctx context.Context,
583583
if bytes > 100<<30 { // 100 GiB
584584
msg := fmt.Sprintf("large table detected: %s (%s). Counting/partitioning queries for parallel "+
585585
"snapshotting may take minutes to hours to execute. This is normal for tables over 100 GiB.",
586-
config.WatermarkTable, utils.FormatTableSize(bytes))
586+
config.WatermarkTable, utils.HumanReadableBytes(bytes))
587587
a.Alerter.LogFlowInfo(ctx, config.FlowJobName, msg)
588588
}
589589
} else {

flow/connectors/bigquery/source_schema.go

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -130,7 +130,7 @@ func (c *BigQueryConnector) GetTablesInSchema(ctx context.Context, schema string
130130
slog.Any("error", err))
131131
tableSize = "Unknown"
132132
} else {
133-
tableSize = utils.FormatTableSize(metadata.NumBytes)
133+
tableSize = utils.HumanReadableBytes(metadata.NumBytes)
134134
}
135135

136136
tableResponse := &protos.TableResponse{

flow/connectors/postgres/cdc.go

Lines changed: 18 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,7 @@ import (
2525
"go.opentelemetry.io/otel/trace"
2626
"go.temporal.io/sdk/log"
2727

28+
"github.com/PeerDB-io/peerdb/flow/alerting"
2829
connmetadata "github.com/PeerDB-io/peerdb/flow/connectors/external_metadata"
2930
"github.com/PeerDB-io/peerdb/flow/connectors/utils"
3031
"github.com/PeerDB-io/peerdb/flow/connectors/utils/monitoring"
@@ -59,6 +60,7 @@ type PostgresCDCSource struct {
5960

6061
// for storing schema delta audit logs to catalog
6162
catalogPool shared.CatalogPool
63+
alerter *alerting.Alerter
6264
otelManager *otel_metrics.OtelManager
6365
hushWarnUnhandledMessageType map[pglogrepl.MessageType]struct{}
6466
hushWarnUnknownTableDetected map[uint32]struct{}
@@ -130,6 +132,7 @@ func (c *PostgresConnector) NewPostgresCDCSource(ctx context.Context, cdcConfig
130132
idToRelKindMap: idToRelKindMap,
131133
publishViaPartitionRoot: publishViaPartitionRoot,
132134
catalogPool: cdcConfig.CatalogPool,
135+
alerter: alerting.NewAlerter(ctx, cdcConfig.CatalogPool, cdcConfig.OtelManager),
133136
otelManager: cdcConfig.OtelManager,
134137
hushWarnUnhandledMessageType: make(map[pglogrepl.MessageType]struct{}),
135138
hushWarnUnknownTableDetected: make(map[uint32]struct{}),
@@ -584,6 +587,7 @@ func PullCdcRecords[Items model.Items](
584587
defer shutdown()
585588

586589
var standByLastLogged time.Time
590+
var largeTxnLastLogged time.Time
587591
nextRecordDeadline := time.Now().Add(req.IdleTimeout)
588592
pkmRequiresResponse := false
589593

@@ -679,11 +683,24 @@ func PullCdcRecords[Items model.Items](
679683
slog.Float64("elapsedMinutes", time.Since(pullStart).Minutes()))
680684
return nil
681685
} else {
686+
accumulatedBytes := totalFetchedBytes.Load()
682687
logger.Info("commit lock, waiting for commit to return records",
683688
slog.Int64("records", totalRecords),
684-
slog.Int64("bytes", totalFetchedBytes.Load()),
689+
slog.Int64("bytes", accumulatedBytes),
685690
slog.Int("channelLen", records.ChannelLen()),
686691
slog.Float64("elapsedMinutes", time.Since(pullStart).Minutes()))
692+
693+
if time.Since(largeTxnLastLogged) > time.Minute {
694+
if !largeTxnLastLogged.IsZero() {
695+
userMsg := fmt.Sprintf(
696+
"Reading a large already-committed transaction off the replication slot; "+
697+
"sync will continue once it's fully received (%d records, %s buffered so far).",
698+
totalRecords, utils.HumanReadableBytes(accumulatedBytes))
699+
p.alerter.LogFlowInfo(ctx, p.flowJobName, userMsg)
700+
}
701+
largeTxnLastLogged = time.Now()
702+
}
703+
687704
waitingForCommit = true
688705
}
689706
} else {

flow/connectors/utils/formatters.go

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -4,8 +4,8 @@ import "fmt"
44

55
var units = []string{"B", "KB", "MB", "GB", "TB", "PB"}
66

7-
// FormatTableSize converts bytes to human-readable format
8-
func FormatTableSize(bytes int64) string {
7+
// HumanReadableBytes converts bytes to human-readable format
8+
func HumanReadableBytes(bytes int64) string {
99
if bytes == 0 {
1010
return "0 B"
1111
}

0 commit comments

Comments
 (0)