Skip to content

Commit 7473628

Browse files
authored
create changestream with timeout (#4166)
Calls client.Watch with a 5 minute context deadline so the driver sends `maxTimeMS` over the wire which is honored by the server. Otherwise server-side default maxTimeMS is used which can sometimes be too short for the initial aggregation. Also added better logging for when change stream is recreated. Fixes: https://linear.app/clickhouse/issue/DBI-672
1 parent cd8fe6d commit 7473628

1 file changed

Lines changed: 22 additions & 4 deletions

File tree

flow/connectors/mongo/cdc.go

Lines changed: 22 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -87,7 +87,8 @@ func (c *MongoConnector) SetupReplication(ctx context.Context, input *protos.Set
8787
if err != nil {
8888
return model.SetupReplicationResult{}, fmt.Errorf("failed to create changestream pipeline: %w", err)
8989
}
90-
changeStream, err := c.client.Watch(ctx, pipeline, changeStreamOpts)
90+
91+
changeStream, err := createChangeStream(c.client, ctx, pipeline, changeStreamOpts)
9192
if err != nil {
9293
return model.SetupReplicationResult{}, fmt.Errorf("failed to start change stream for storing initial resume token: %w", err)
9394
}
@@ -156,7 +157,7 @@ func (c *MongoConnector) PullRecords(
156157
return err
157158
}
158159

159-
changeStream, err := c.client.Watch(ctx, pipeline, changeStreamOpts)
160+
changeStream, err := createChangeStream(c.client, ctx, pipeline, changeStreamOpts)
160161
if err != nil {
161162
if isResumeTokenNotFoundError(err) && resumeToken != nil {
162163
timestamp, err := decodeTimestampFromResumeToken(resumeToken)
@@ -165,7 +166,7 @@ func (c *MongoConnector) PullRecords(
165166
}
166167
changeStreamOpts.SetStartAtOperationTime(&timestamp)
167168
changeStreamOpts.SetResumeAfter(nil)
168-
changeStream, err = c.client.Watch(ctx, pipeline, changeStreamOpts)
169+
changeStream, err = createChangeStream(c.client, ctx, pipeline, changeStreamOpts)
169170
if err != nil {
170171
return fmt.Errorf("failed to recreate change stream: %w", err)
171172
}
@@ -299,7 +300,7 @@ func (c *MongoConnector) PullRecords(
299300
changeStreamOpts.SetStartAtOperationTime(nil)
300301
}
301302

302-
changeStream, err = c.client.Watch(ctx, pipeline, changeStreamOpts)
303+
changeStream, err = createChangeStream(c.client, ctx, pipeline, changeStreamOpts)
303304
if err != nil {
304305
return err
305306
}
@@ -325,13 +326,16 @@ func (c *MongoConnector) PullRecords(
325326
if err := recreateChangeStream(false); err != nil {
326327
return fmt.Errorf("failed to recreate change stream: %w", err)
327328
}
329+
c.logger.Info("[mongo] recreated change stream because context deadline exceeded",
330+
slog.Duration("elapsed", time.Since(pullStart)))
328331
continue
329332
}
330333

331334
if isResumeTokenNotFoundError(err) {
332335
if err := recreateChangeStream(true); err != nil {
333336
return fmt.Errorf("failed to recreate change stream: %w", err)
334337
}
338+
c.logger.Info("[mongo] recreated change stream because resume token not found", slog.Duration("elapsed", time.Since(pullStart)))
335339
continue
336340
}
337341

@@ -461,6 +465,20 @@ func createPipeline(tableNameMapping map[string]model.NameAndExclude) (mongo.Pip
461465
return pipeline, nil
462466
}
463467

468+
// createChangeStream calls client.Watch with a 5 minute context deadline
469+
// so the driver sends it as maxTimeMS over the wire. Otherwise, server-side
470+
// default maxTimeMS is used which can sometimes be too short.
471+
func createChangeStream(
472+
client *mongo.Client,
473+
parent context.Context,
474+
pipeline mongo.Pipeline,
475+
opts *options.ChangeStreamOptionsBuilder,
476+
) (*mongo.ChangeStream, error) {
477+
watchCtx, cancel := context.WithTimeout(parent, 5*time.Minute)
478+
defer cancel()
479+
return client.Watch(watchCtx, pipeline, opts)
480+
}
481+
464482
// This can happen if the resumeToken we are attempting to `ResumeAfter` refers to a table that has been
465483
// filtered out of the change stream pipeline (for example, if a user pauses and edits a mirror). If
466484
// this happens, we decode the resumeToken and extract its operation time, and start a new changeStream

0 commit comments

Comments
 (0)