Skip to content

Commit

Permalink
client, roachpb: eliminate log spam when loadgens are killed
Browse files Browse the repository at this point in the history
When the TPCC loadgen is CTRL-C'ed, the logs are spammed with:
I180906 22:02:41.239771 27177127 internal/client/txn.go:625  [n1] async rollback failed: TransactionStatusError: already committed (REASON_UNKNOWN): "sql txn" id=57c518aa key=/Table/61/1/1224/0 rw=true pri=0.03781170 iso=SERIALIZABLE stat=COMMITTED epo=0 ts=1536271361.068457287,0 orig=1536271361.068457287,0 max=1536271361.073978228,0 wto=false rop=false seq=11 int=5

The "async rollback" part refers to the rollback being done with a
canceled ctx (presumably a dropped connection's ctx). I believe the
error happens because there's a commit in flight when the ctx is
canceled. This patch lowers the message's level for this case.

Release note: None
  • Loading branch information
andreimatei committed Sep 7, 2018
1 parent 2256588 commit c32a379
Show file tree
Hide file tree
Showing 6 changed files with 201 additions and 177 deletions.
11 changes: 10 additions & 1 deletion pkg/internal/client/txn.go
Expand Up @@ -626,7 +626,16 @@ func (txn *Txn) rollback(ctx context.Context) *roachpb.Error {
var ba roachpb.BatchRequest
ba.Add(endTxnReq(false /* commit */, nil /* deadline */, false /* systemConfigTrigger */))
if _, pErr := txn.Send(ctx, ba); pErr != nil {
log.Infof(ctx, "async rollback failed: %s", pErr)
if statusErr, ok := pErr.GetDetail().(*roachpb.TransactionStatusError); ok &&
statusErr.Reason == roachpb.TransactionStatusError_REASON_TXN_COMMITTED {
// A common cause of these async rollbacks failing is when they're
// triggered by a ctx canceled while a commit is in-flight (and it's too
// late for it to be canceled), and so the rollback finds the txn to be
// already committed. We don't spam the logs with those.
log.VEventf(ctx, 2, "async rollback failed: %s", pErr)
} else {
log.Infof(ctx, "async rollback failed: %s", pErr)
}
}
}); err != nil {
cancel()
Expand Down
9 changes: 9 additions & 0 deletions pkg/roachpb/errors.go
Expand Up @@ -410,6 +410,15 @@ func NewTransactionNotFoundStatusError() *TransactionStatusError {
}
}

// NewTransactionCommittedStatusError initializes a new TransactionStatusError
// with a REASON_TXN_COMMITTED.
func NewTransactionCommittedStatusError() *TransactionStatusError {
return &TransactionStatusError{
Msg: "already committed",
Reason: TransactionStatusError_REASON_TXN_COMMITTED,
}
}

func (e *TransactionStatusError) Error() string {
return fmt.Sprintf("TransactionStatusError: %s (%s)", e.Msg, e.Reason)
}
Expand Down

0 comments on commit c32a379

Please sign in to comment.