Skip to content

Commit

Permalink
sql: plumb isCopy down to event log
Browse files Browse the repository at this point in the history
Previously, we relied on the `txn` being filled to log `COPY`
statements. This is however inaccurate - `txn` may be nil if `COPY` is
the first statement encountered. This meant that the first COPY
encountered would not be logged.

Instead, plumb down `isCopy` and use `timeutil.Now()` if it is a COPY
related statement.

Release justification: logging related critical fix

Release note: None
  • Loading branch information
otan committed Aug 31, 2022
1 parent d35c174 commit c20ba1b
Show file tree
Hide file tree
Showing 4 changed files with 13 additions and 2 deletions.
1 change: 1 addition & 0 deletions pkg/sql/conn_executor.go
Original file line number Diff line number Diff line change
Expand Up @@ -2457,6 +2457,7 @@ func (ex *connExecutor) execCopyIn(
ex.planner.maybeLogStatement(
ctx,
ex.executorType,
true, /* isCopy */
int(ex.state.mu.autoRetryCounter),
ex.extraTxnState.txnCounter,
numInsertedRows,
Expand Down
1 change: 1 addition & 0 deletions pkg/sql/conn_executor_exec.go
Original file line number Diff line number Diff line change
Expand Up @@ -1070,6 +1070,7 @@ func (ex *connExecutor) dispatchToExecutionEngine(
planner.maybeLogStatement(
ctx,
ex.executorType,
false, /* isCopy */
int(ex.state.mu.autoRetryCounter),
ex.extraTxnState.txnCounter,
res.RowsAffected(),
Expand Down
8 changes: 7 additions & 1 deletion pkg/sql/event_log.go
Original file line number Diff line number Diff line change
Expand Up @@ -164,6 +164,9 @@ type eventLogOptions struct {

// Additional redaction options, if necessary.
rOpts redactionOptions

// isCopy notes whether the current event is related to COPY.
isCopy bool
}

// redactionOptions contains instructions on how to redact the SQL
Expand Down Expand Up @@ -276,7 +279,10 @@ func logEventInternalForSQLStatements(
) error {
// Inject the common fields into the payload provided by the caller.
injectCommonFields := func(event logpb.EventPayload) error {
if txn != nil {
if opts.isCopy {
// No txn is set for COPY, so use now instead.
event.CommonDetails().Timestamp = timeutil.Now().UnixNano()
} else {
event.CommonDetails().Timestamp = txn.ReadTimestamp().WallTime
}
sqlCommon, ok := event.(eventpb.EventWithCommonSQLPayload)
Expand Down
5 changes: 4 additions & 1 deletion pkg/sql/exec_log.go
Original file line number Diff line number Diff line change
Expand Up @@ -154,6 +154,7 @@ var sqlPerfInternalLogger log.ChannelLogger = log.SqlInternalPerf
func (p *planner) maybeLogStatement(
ctx context.Context,
execType executorType,
isCopy bool,
numRetries, txnCounter, rows int,
err error,
queryReceived time.Time,
Expand All @@ -162,12 +163,13 @@ func (p *planner) maybeLogStatement(
stmtFingerprintID roachpb.StmtFingerprintID,
queryStats *topLevelQueryStats,
) {
p.maybeLogStatementInternal(ctx, execType, numRetries, txnCounter, rows, err, queryReceived, hasAdminRoleCache, telemetryLoggingMetrics, stmtFingerprintID, queryStats)
p.maybeLogStatementInternal(ctx, execType, isCopy, numRetries, txnCounter, rows, err, queryReceived, hasAdminRoleCache, telemetryLoggingMetrics, stmtFingerprintID, queryStats)
}

func (p *planner) maybeLogStatementInternal(
ctx context.Context,
execType executorType,
isCopy bool,
numRetries, txnCounter, rows int,
err error,
startTime time.Time,
Expand Down Expand Up @@ -373,6 +375,7 @@ func (p *planner) maybeLogStatementInternal(
// see a copy of the execution on the DEV Channel.
dst: LogExternally | LogToDevChannelIfVerbose,
verboseTraceLevel: execType.vLevel(),
isCopy: isCopy,
},
&eventpb.QueryExecute{CommonSQLExecDetails: execDetails})
}
Expand Down

0 comments on commit c20ba1b

Please sign in to comment.