mesh-mail: retry the outcome's own write on a changed revision, and never ack or emit an outcome that could not be kept (review round 1 finding 5; issue 1198)
This commit is contained in:
@@ -186,3 +186,48 @@ func TestRecordOutcomeStillRecordsFailedWhenTheTellsPendingIndexCannotBeWritten(
|
|||||||
t.Fatalf("emitted %d time(s) despite the index failing", len(emit.calls))
|
t.Fatalf("emitted %d time(s) despite the index failing", len(emit.calls))
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// review round 1 finding 5: if writing "sent" cannot be kept (even retried on a changed revision), the
|
||||||
|
// message is never acknowledged and mail.send.sent is never emitted — a mail actually sent is never
|
||||||
|
// silently announced successful when the record never actually carried it.
|
||||||
|
func TestRecordOutcomeOnSentDoesNotAckOrEmitWhenTheWriteCannotBeKept(t *testing.T) {
|
||||||
|
req, claimed, rev, sends := outcomeTestClaim(t, 1)
|
||||||
|
sends.failKey, sends.failErr = req.ID, errors.New("the store is down")
|
||||||
|
emit := &memEmit{}
|
||||||
|
|
||||||
|
d, action, _, err := recordOutcome(sends, emit.emit, req, claimed, rev, nil, judgedAt.Add(2*time.Minute))
|
||||||
|
if err == nil {
|
||||||
|
t.Fatalf("the write failure was not reported")
|
||||||
|
}
|
||||||
|
if action != actionLeave {
|
||||||
|
t.Fatalf("action: %v, want actionLeave (left to the bus, never acked)", action)
|
||||||
|
}
|
||||||
|
if len(emit.calls) != 0 {
|
||||||
|
t.Fatalf("emitted mail.send.sent despite the write never being kept: %+v", emit.calls)
|
||||||
|
}
|
||||||
|
// The kept record is unaffected: still "sending", as claimQueuedSend originally left it.
|
||||||
|
kept, _, ok, kerr := getSend(sends, req.ID)
|
||||||
|
if kerr != nil || !ok || kept.Decided == nil || kept.Decided.Outcome != "sending" {
|
||||||
|
t.Fatalf("the record changed despite the write failing: %v %v %+v (returned %+v)", kerr, ok, kept.Decided, d)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// Same finding, for a failed outcome (refused): the message is left to the bus, never terminated, and
|
||||||
|
// mail.send.failed is never emitted, when the write itself cannot be kept.
|
||||||
|
func TestRecordOutcomeOnRefusedDoesNotTerminateOrEmitWhenTheWriteCannotBeKept(t *testing.T) {
|
||||||
|
req, claimed, rev, sends := outcomeTestClaim(t, 1)
|
||||||
|
sends.failKey, sends.failErr = req.ID, errors.New("the store is down")
|
||||||
|
emit := &memEmit{}
|
||||||
|
|
||||||
|
_, action, _, err := recordOutcome(sends, emit.emit, req, claimed, rev, &SendError{Outcome: Refused, Err: errors.New("550 no such mailbox")},
|
||||||
|
judgedAt.Add(2*time.Minute))
|
||||||
|
if err == nil {
|
||||||
|
t.Fatalf("the write failure was not reported")
|
||||||
|
}
|
||||||
|
if action != actionLeave {
|
||||||
|
t.Fatalf("action: %v, want actionLeave", action)
|
||||||
|
}
|
||||||
|
if len(emit.calls) != 0 {
|
||||||
|
t.Fatalf("emitted mail.send.failed despite the write never being kept: %+v", emit.calls)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|||||||
@@ -893,13 +893,18 @@ const MostAttempts = 5
|
|||||||
// recordOutcome has written the decision: Ack (sent), NakWithDelay (retrying, not the last attempt yet) or
|
// recordOutcome has written the decision: Ack (sent), NakWithDelay (retrying, not the last attempt yet) or
|
||||||
// Term (failed, or not proven — the bus is never asked to redeliver those; a dead letter past the fifth
|
// Term (failed, or not proven — the bus is never asked to redeliver those; a dead letter past the fifth
|
||||||
// attempt is still reached by Term, since clause 10 records failed itself rather than waiting for the bus's
|
// attempt is still reached by Term, since clause 10 records failed itself rather than waiting for the bus's
|
||||||
// own max-deliveries to notice).
|
// own max-deliveries to notice). actionLeave is none of these: the record's own write could not be kept
|
||||||
|
// (even after a retry on a changed revision), so nothing is emitted and the message is left entirely to
|
||||||
|
// the bus — a later redelivery finds the record still at its previous outcome and reconciles from there,
|
||||||
|
// never a send silently announced sent, failed or retrying when it was not actually kept that way (novox/hq
|
||||||
|
// review round 1 finding 5).
|
||||||
type msgAction int
|
type msgAction int
|
||||||
|
|
||||||
const (
|
const (
|
||||||
actionAck msgAction = iota
|
actionAck msgAction = iota
|
||||||
actionRetry
|
actionRetry
|
||||||
actionTerm
|
actionTerm
|
||||||
|
actionLeave
|
||||||
)
|
)
|
||||||
|
|
||||||
// recordOutcome writes the final decision for one claimed send once SendMail has run (or could not even be
|
// recordOutcome writes the final decision for one claimed send once SendMail has run (or could not even be
|
||||||
@@ -908,7 +913,12 @@ const (
|
|||||||
// with the message next. Attempt (req's own, from the claim) decides retrying from failed on a not-taken
|
// with the message next. Attempt (req's own, from the claim) decides retrying from failed on a not-taken
|
||||||
// failure: the fifth attempt always fails rather than retries again (novox/hq ADR 0436 clauses 10, 11).
|
// failure: the fifth attempt always fails rather than retries again (novox/hq ADR 0436 clauses 10, 11).
|
||||||
func recordOutcome(store SendStore, emit Emit, req SendRequest, claimed SendDecision, rev uint64, sendErr error, now time.Time) (SendDecision, msgAction, time.Duration, error) {
|
func recordOutcome(store SendStore, emit Emit, req SendRequest, claimed SendDecision, rev uint64, sendErr error, now time.Time) (SendDecision, msgAction, time.Duration, error) {
|
||||||
write := func(d SendDecision, final, tellWorthy bool) (SendDecision, error) {
|
// write keeps d, retrying once on a changed revision (re-reading the send and trying again with its
|
||||||
|
// fresh one) before giving up: kept is false only when the record's own write could not be kept even
|
||||||
|
// after that retry, in which case the caller emits nothing and leaves the message to the bus entirely —
|
||||||
|
// never announcing an outcome (sent, failed, retrying) that was not actually recorded (novox/hq review
|
||||||
|
// round 1 finding 5).
|
||||||
|
write := func(d SendDecision, final, tellWorthy bool) (result SendDecision, kept bool, outErr error) {
|
||||||
var indexErr error
|
var indexErr error
|
||||||
if tellWorthy {
|
if tellWorthy {
|
||||||
// Indexed for a tell BEFORE the record carries the outcome that owes it (novox/hq review round
|
// Indexed for a tell BEFORE the record carries the outcome that owes it (novox/hq review round
|
||||||
@@ -916,11 +926,21 @@ func recordOutcome(store SendStore, emit Emit, req SendRequest, claimed SendDeci
|
|||||||
// outcome does land; tellSend itself tolerates finding it still sending, queued or retrying.
|
// outcome does land; tellSend itself tolerates finding it still sending, queued or retrying.
|
||||||
indexErr = addTellPending(store, req.ID)
|
indexErr = addTellPending(store, req.ID)
|
||||||
}
|
}
|
||||||
result, _, err := settleSend(store, req, rev, d)
|
curReq, curRev := req, rev
|
||||||
if err != nil {
|
var writeErr error
|
||||||
// The attempt (and its SMTP outcome) stand either way; the caller logs this. A redelivery (or the
|
for attempt := 0; attempt < 2; attempt++ {
|
||||||
// sweep, for a send stuck mid-write) finds whatever the real kept state is and reconciles.
|
result, _, writeErr = settleSend(store, curReq, curRev, d)
|
||||||
return d, errOr(indexErr, err)
|
if writeErr == nil || !errors.Is(writeErr, stdio.ErrChanged) {
|
||||||
|
break
|
||||||
|
}
|
||||||
|
fresh, freshRev, ok, rerr := getSend(store, req.ID)
|
||||||
|
if rerr != nil || !ok {
|
||||||
|
break
|
||||||
|
}
|
||||||
|
curReq, curRev = fresh, freshRev
|
||||||
|
}
|
||||||
|
if writeErr != nil {
|
||||||
|
return d, false, errOr(indexErr, fmt.Errorf("the send %s's outcome could not be kept, even retried on a changed revision (%w)", req.ID, writeErr))
|
||||||
}
|
}
|
||||||
if final {
|
if final {
|
||||||
// Only once the outcome is durably recorded is the sender-pending index's entry dropped: from
|
// Only once the outcome is durably recorded is the sender-pending index's entry dropped: from
|
||||||
@@ -929,10 +949,13 @@ func recordOutcome(store SendStore, emit Emit, req SendRequest, claimed SendDeci
|
|||||||
indexErr = errOr(indexErr, fmt.Errorf("dropping %s from the sender-pending index: %w", req.ID, rmErr))
|
indexErr = errOr(indexErr, fmt.Errorf("dropping %s from the sender-pending index: %w", req.ID, rmErr))
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
return result, indexErr
|
return result, true, indexErr
|
||||||
}
|
}
|
||||||
if sendErr == nil {
|
if sendErr == nil {
|
||||||
d, err := write(SendDecision{At: now, Outcome: "sent", Warrant: claimed.Warrant, Attempt: claimed.Attempt}, true, false)
|
d, kept, err := write(SendDecision{At: now, Outcome: "sent", Warrant: claimed.Warrant, Attempt: claimed.Attempt}, true, false)
|
||||||
|
if !kept {
|
||||||
|
return d, actionLeave, 0, err
|
||||||
|
}
|
||||||
_ = emit(MailSendSent, req.ID, OutcomeEvent{Send: req.ID, Account: req.Account, Outcome: d.Outcome})
|
_ = emit(MailSendSent, req.ID, OutcomeEvent{Send: req.ID, Account: req.Account, Outcome: d.Outcome})
|
||||||
return d, actionAck, 0, err
|
return d, actionAck, 0, err
|
||||||
}
|
}
|
||||||
@@ -945,25 +968,37 @@ func recordOutcome(store SendStore, emit Emit, req SendRequest, claimed SendDeci
|
|||||||
}
|
}
|
||||||
switch se.Outcome {
|
switch se.Outcome {
|
||||||
case Refused:
|
case Refused:
|
||||||
d, err := write(SendDecision{At: now, Outcome: "failed: " + se.Err.Error(), Warrant: claimed.Warrant,
|
d, kept, err := write(SendDecision{At: now, Outcome: "failed: " + se.Err.Error(), Warrant: claimed.Warrant,
|
||||||
Attempt: claimed.Attempt, Error: se.Err.Error()}, true, true)
|
Attempt: claimed.Attempt, Error: se.Err.Error()}, true, true)
|
||||||
|
if !kept {
|
||||||
|
return d, actionLeave, 0, err
|
||||||
|
}
|
||||||
_ = emit(MailSendFailed, req.ID, OutcomeEvent{Send: req.ID, Account: req.Account, Outcome: d.Outcome})
|
_ = emit(MailSendFailed, req.ID, OutcomeEvent{Send: req.ID, Account: req.Account, Outcome: d.Outcome})
|
||||||
return d, actionTerm, 0, err
|
return d, actionTerm, 0, err
|
||||||
case NotProven:
|
case NotProven:
|
||||||
d, err := write(SendDecision{At: now, Outcome: "not proven", Warrant: claimed.Warrant, Attempt: claimed.Attempt,
|
d, kept, err := write(SendDecision{At: now, Outcome: "not proven", Warrant: claimed.Warrant, Attempt: claimed.Attempt,
|
||||||
Error: se.Err.Error()}, true, true)
|
Error: se.Err.Error()}, true, true)
|
||||||
|
if !kept {
|
||||||
|
return d, actionLeave, 0, err
|
||||||
|
}
|
||||||
_ = emit(MailSendFailed, req.ID, OutcomeEvent{Send: req.ID, Account: req.Account, Outcome: d.Outcome})
|
_ = emit(MailSendFailed, req.ID, OutcomeEvent{Send: req.ID, Account: req.Account, Outcome: d.Outcome})
|
||||||
return d, actionTerm, 0, err
|
return d, actionTerm, 0, err
|
||||||
default: // NotTaken
|
default: // NotTaken
|
||||||
if claimed.Attempt >= MostAttempts {
|
if claimed.Attempt >= MostAttempts {
|
||||||
d, err := write(SendDecision{At: now, Outcome: "failed: " + se.Err.Error(), Warrant: claimed.Warrant,
|
d, kept, err := write(SendDecision{At: now, Outcome: "failed: " + se.Err.Error(), Warrant: claimed.Warrant,
|
||||||
Attempt: claimed.Attempt, Error: se.Err.Error()}, true, true)
|
Attempt: claimed.Attempt, Error: se.Err.Error()}, true, true)
|
||||||
|
if !kept {
|
||||||
|
return d, actionLeave, 0, err
|
||||||
|
}
|
||||||
_ = emit(MailSendFailed, req.ID, OutcomeEvent{Send: req.ID, Account: req.Account, Outcome: d.Outcome})
|
_ = emit(MailSendFailed, req.ID, OutcomeEvent{Send: req.ID, Account: req.Account, Outcome: d.Outcome})
|
||||||
return d, actionTerm, 0, err
|
return d, actionTerm, 0, err
|
||||||
}
|
}
|
||||||
delay := RetryDelays[claimed.Attempt-1]
|
delay := RetryDelays[claimed.Attempt-1]
|
||||||
d, err := write(SendDecision{At: now, Outcome: "retrying", Warrant: claimed.Warrant, Attempt: claimed.Attempt,
|
d, kept, err := write(SendDecision{At: now, Outcome: "retrying", Warrant: claimed.Warrant, Attempt: claimed.Attempt,
|
||||||
Error: se.Err.Error(), NextAttempt: now.Add(delay)}, false, false)
|
Error: se.Err.Error(), NextAttempt: now.Add(delay)}, false, false)
|
||||||
|
if !kept {
|
||||||
|
return d, actionLeave, 0, err
|
||||||
|
}
|
||||||
return d, actionRetry, delay, err // not a final outcome: no emit (clause 11 names only sent and failed)
|
return d, actionRetry, delay, err // not a final outcome: no emit (clause 11 names only sent and failed)
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -259,6 +259,10 @@ func (h *senderHandler) handle(msg *process.Message) {
|
|||||||
if err := msg.Term(); err != nil {
|
if err := msg.Term(); err != nil {
|
||||||
h.logf("[mesh-mail] send: terminating %s: %v", q.Send, err)
|
h.logf("[mesh-mail] send: terminating %s: %v", q.Send, err)
|
||||||
}
|
}
|
||||||
|
case actionLeave:
|
||||||
|
// The outcome's own write could not be kept, even retried on a changed revision (novox/hq review
|
||||||
|
// round 1 finding 5): nothing was emitted above, and nothing is done to the message either — left
|
||||||
|
// entirely to the bus, so a later redelivery finds the record still at its previous outcome.
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
|||||||
Reference in New Issue
Block a user