Add deferred reporting finalization

docs/roadmap/implementation.md

@@ -168,7 +168,7 @@ assert intact operations without imposing an order among concurrent callers.
 
 ## Stage 4: Implement deferred delivery and finalization
 
-Status: pending.
+Status: complete.
 
 1. Implement `AtEnd` and the selected value-type `DeferredReporter` methods.
    Copy callback lists on submission. Queue messages in submission order,

reporter.go

@@ -40,6 +40,7 @@ type reportingState struct {
 	mode        reportingMode
 	progress    bool
 	progressSet bool
+	deferred    []deferredMessage
 }
 
 type destinationState struct {
@@ -51,6 +52,12 @@ type destinationState struct {
 	writeError  error
 }
 
+type deferredMessage struct {
+	category messageCategory
+	message  string
+	details  []Detail
+}
+
 // Reporter coordinates presentation and delivery for one invocation.
 //
 // The invocation supplies the reporter. Consumers use Output for substantive
@@ -59,6 +66,12 @@ type Reporter struct {
 	state *reportingState
 }
 
+// DeferredReporter queues messages for delivery during invocation finalization.
+// Copies share the same invocation reporting state.
+type DeferredReporter struct {
+	state *reportingState
+}
+
 type managedOutputWriter struct {
 	state       *reportingState
 	destination reportingDestination
@@ -149,6 +162,162 @@ func (r *Reporter) Progress(message string, details ...Detail) error {
 	return r.submitMessage(categoryProgress, message, details)
 }
 
+// AtEnd returns a view for messages delivered after the handler returns.
+func (r *Reporter) AtEnd() DeferredReporter {
+	if r == nil {
+		return DeferredReporter{}
+	}
+	return DeferredReporter{state: r.state}
+}
+
+// Info queues an informational message for invocation finalization.
+func (r DeferredReporter) Info(message string, details ...Detail) error {
+	return r.enqueue(categoryInfo, message, details)
+}
+
+// Warn queues a warning message for invocation finalization.
+func (r DeferredReporter) Warn(message string, details ...Detail) error {
+	return r.enqueue(categoryWarning, message, details)
+}
+
+// Debug queues a debug message for invocation finalization.
+func (r DeferredReporter) Debug(message string, details ...Detail) error {
+	return r.enqueue(categoryDebug, message, details)
+}
+
+func (r DeferredReporter) enqueue(category messageCategory, message string, details []Detail) error {
+	if r.state == nil {
+		return ErrReporterClosed
+	}
+	state := r.state
+	state.mu.Lock()
+	defer state.mu.Unlock()
+	if state.closed {
+		return ErrReporterClosed
+	}
+	state.deferred = append(state.deferred, deferredMessage{
+		category: category,
+		message:  message,
+		details:  append([]Detail(nil), details...),
+	})
+	return nil
+}
+
+func (r *Reporter) finalize(outcome Outcome, completion func(*Reporter)) Outcome {
+	if r == nil || r.state == nil {
+		return normalizeOutcome(outcome)
+	}
+	state := r.state
+	state.mu.Lock()
+	if state.closed {
+		outcome.Presentation = state.presentationLocked()
+		state.mu.Unlock()
+		return normalizeOutcome(outcome)
+	}
+	deferred := append([]deferredMessage(nil), state.deferred...)
+	state.deferred = nil
+	state.mu.Unlock()
+
+	for _, message := range deferred {
+		_ = r.submitMessage(message.category, message.message, message.details)
+	}
+	if completion != nil {
+		completion(r)
+	}
+
+	state.mu.Lock()
+	if presentationFailedLocked(state) {
+		outcome = applyPresentationFailure(outcome)
+	}
+	if outcome.Status != 0 {
+		outcome = ensureFallbackExplanation(outcome)
+		if state.diagnostics.writeError == nil {
+			_ = renderTerminalLocked(state, outcome.Explanation)
+		}
+	}
+	if presentationFailedLocked(state) {
+		outcome = applyPresentationFailure(outcome)
+	}
+	state.closed = true
+	state.deferred = nil
+	outcome.Presentation = state.presentationLocked()
+	state.mu.Unlock()
+	return normalizeOutcome(outcome)
+}
+
+func normalizeOutcome(outcome Outcome) Outcome {
+	if outcome.Kind == "" && outcome.Status == 0 && outcome.Domain == "" {
+		outcome.Kind = OutcomeSuccess
+	}
+	return outcome
+}
+
+func presentationFailedLocked(state *reportingState) bool {
+	return state.output.renderError != nil || state.output.writeError != nil ||
+		state.diagnostics.renderError != nil || state.diagnostics.writeError != nil
+}
+
+func applyPresentationFailure(outcome Outcome) Outcome {
+	switch outcome.Kind {
+	case OutcomeDomain:
+		if outcome.Status == 0 {
+			outcome.Status = 1
+		}
+	case OutcomeSuccess, OutcomeUsage, OutcomeOperational:
+		outcome.Kind = OutcomeOperational
+		outcome.Status = 1
+	case "":
+		outcome.Kind = OutcomeOperational
+		outcome.Status = 1
+	}
+	return outcome
+}
+
+func ensureFallbackExplanation(outcome Outcome) Outcome {
+	if outcome.Explanation.Message != "" {
+		return outcome
+	}
+	for _, detail := range outcome.Explanation.Details {
+		if detail != nil {
+			return outcome
+		}
+	}
+	outcome.Explanation = Explanation{Message: "Command failed."}
+	return outcome
+}
+
+func renderTerminalLocked(state *reportingState, explanation Explanation) error {
+	destination := state.destination(destinationDiagnostics)
+	destination.submitted = true
+	var renderErr, writeErr error
+	if explanation.Message != "" {
+		writer := &coordinatedWriter{state: state, destination: destinationDiagnostics}
+		_, _ = writer.Write([]byte("ERROR: " + strings.TrimSuffix(explanation.Message, "\n") + "\n"))
+		writeErr = writer.writeError
+	}
+	if writeErr == nil {
+		for _, detail := range explanation.Details {
+			if detail == nil {
+				continue
+			}
+			writer := &coordinatedWriter{state: state, destination: destinationDiagnostics}
+			detailErr := detail(writer)
+			detailWriteErr := writer.writeError
+			detailRenderErr := recordRendererErrorLocked(state, destinationDiagnostics, detailErr, detailWriteErr)
+			if renderErr == nil {
+				renderErr = detailRenderErr
+			}
+			if writeErr == nil {
+				writeErr = detailWriteErr
+			}
+		}
+	}
+	if renderErr == nil && writeErr == nil {
+		destination.delivered = true
+	}
+	return combineOperationErrors(renderErr, writeErr)
+}
+
 func (r *Reporter) submitMessage(category messageCategory, message string, details []Detail) error {
 	if r == nil || r.state == nil {
 		return ErrReporterClosed

reporter_test.go

@@ -467,3 +467,206 @@ func TestReporterEmptyHeadingDoesNotAddPrefixOrBlankLine(t *testing.T) {
 		t.Fatal("empty heading added a category prefix")
 	}
 }
+
+func TestReporterFinalizesDeferredMessagesBeforeCompletionAndExplanation(t *testing.T) {
+	var output, diagnostics bytes.Buffer
+	reporter := newReporter(Streams{Out: &output, Err: &diagnostics})
+	reporter.setVisibility(modeDebug, false, false)
+	if err := reporter.Info("started"); err != nil {
+		t.Fatal(err)
+	}
+	deferred := reporter.AtEnd()
+	if err := deferred.Warn("first deferred"); err != nil {
+		t.Fatal(err)
+	}
+	if err := deferred.Info("second deferred"); err != nil {
+		t.Fatal(err)
+	}
+	outcome := reporter.finalize(Failure("operation failed"), func(r *Reporter) {
+		_ = r.Debug("handler complete")
+	})
+	want := "started\nWARN: first deferred\nsecond deferred\nDEBUG: handler complete\nERROR: operation failed\n"
+	if got := diagnostics.String(); got != want {
+		t.Fatalf("diagnostics = %q, want %q", got, want)
+	}
+	if outcome.Presentation.Diagnostics.State != DeliveryComplete || outcome.Presentation.Output.State != DeliveryNone {
+		t.Fatalf("presentation = %#v", outcome.Presentation)
+	}
+}
+
+func TestReporterDeferredSubmissionCopiesDetailsAndRetainsDeferredFailures(t *testing.T) {
+	var diagnostics bytes.Buffer
+	reporter := newReporter(Streams{Err: &diagnostics})
+	reporter.setVisibility(modeVerbose, false, false)
+	writeFirst := Detail(func(w io.Writer) error { _, err := io.WriteString(w, "first detail\n"); return err })
+	writeSecond := Detail(func(w io.Writer) error { _, err := io.WriteString(w, "second detail\n"); return err })
+	details := []Detail{writeFirst}
+	deferred := reporter.AtEnd()
+	if err := deferred.Warn("queued", details...); err != nil {
+		t.Fatal(err)
+	}
+	details[0] = writeSecond
+	details = append(details, writeSecond)
+	outcome := reporter.finalize(Success(), nil)
+	if got, want := diagnostics.String(), "WARN: queued\nfirst detail\n"; got != want {
+		t.Fatalf("diagnostics = %q, want %q", got, want)
+	}
+	if outcome.Kind != OutcomeSuccess || outcome.Status != 0 || outcome.Presentation.Diagnostics.State != DeliveryComplete {
+		t.Fatalf("outcome = %#v", outcome)
+	}
+
+	renderErr := errors.New("deferred renderer failed")
+	failedReporter := newReporter(Streams{Err: io.Discard})
+	failedReporter.setVisibility(modeQuiet, false, false)
+	if err := failedReporter.AtEnd().Warn("hidden", func(io.Writer) error { return renderErr }); err != nil {
+		t.Fatal(err)
+	}
+	failed := failedReporter.finalize(Success(), nil)
+	if failed.Kind != OutcomeOperational || failed.Status != 1 || !errors.Is(failed.Presentation.Diagnostics.RenderError, renderErr) {
+		t.Fatalf("deferred renderer failure outcome = %#v", failed)
+	}
+}
+
+func TestReporterFinalizationFallbackAndCauseRetention(t *testing.T) {
+	var diagnostics bytes.Buffer
+	cause := errors.New("sensitive operation detail")
+	reporter := newReporter(Streams{Err: &diagnostics})
+	outcome := reporter.finalize(Failure("").WithCause(cause), nil)
+	if outcome.Explanation.Message != "Command failed." {
+		t.Fatalf("fallback explanation = %#v", outcome.Explanation)
+	}
+	if !errors.Is(outcome.Cause, cause) || !strings.Contains(diagnostics.String(), "ERROR: Command failed.\n") {
+		t.Fatalf("outcome=%#v output=%q", outcome, diagnostics.String())
+	}
+	if strings.Contains(diagnostics.String(), cause.Error()) {
+		t.Fatalf("cause was rendered automatically: %q", diagnostics.String())
+	}
+
+	var zeroDiagnostics bytes.Buffer
+	zeroReporter := newReporter(Streams{Err: &zeroDiagnostics})
+	zero := zeroReporter.finalize(Outcome{Cause: cause}, nil)
+	if zero.Kind != OutcomeSuccess || zero.Status != 0 || !errors.Is(zero.Cause, cause) || zeroDiagnostics.Len() != 0 {
+		t.Fatalf("zero-value outcome with cause changed classification: %#v output=%q", zero, zeroDiagnostics.String())
+	}
+
+	var native bytes.Buffer
+	nativeReporter := newReporter(Streams{Err: &native})
+	nativeOutcome := nativeReporter.finalize(Failure("", func(io.Writer) error { return nil }), nil)
+	if nativeOutcome.Explanation.Message != "" || native.String() != "" {
+		t.Fatalf("explicit zero-byte explanation changed: outcome=%#v output=%q", nativeOutcome, native.String())
+	}
+}
+
+func TestReporterPresentationFailureChangesOutcomeAndPreservesDomain(t *testing.T) {
+	outputErr := errors.New("report write failed")
+	var diagnostics bytes.Buffer
+	reporter := newReporter(Streams{Out: &reporterTestWriter{err: outputErr}, Err: &diagnostics})
+	_, _ = reporter.Output().Write([]byte("partial"))
+	cause := errors.New("operation cause")
+	outcome := reporter.finalize(Success().WithCause(cause), nil)
+	if outcome.Kind != OutcomeOperational || outcome.Status != 1 || !errors.Is(outcome.Cause, cause) {
+		t.Fatalf("success presentation failure outcome = %#v", outcome)
+	}
+	if !errors.Is(outcome.Presentation.Output.WriteError, outputErr) || diagnostics.String() != "ERROR: Command failed.\n" {
+		t.Fatalf("presentation=%#v diagnostics=%q", outcome.Presentation, diagnostics.String())
+	}
+
+	for _, test := range []struct {
+		name       string
+		outcome    Outcome
+		wantKind   OutcomeKind
+		wantStatus int
+	}{
+		{name: "usage becomes operational", outcome: Usage("invalid request").WithCause(cause), wantKind: OutcomeOperational, wantStatus: 1},
+		{name: "operational stays operational", outcome: Failure("operation failed").WithCause(cause), wantKind: OutcomeOperational, wantStatus: 1},
+		{name: "domain nonzero is retained", outcome: Domain("validation", 5).WithExplanation("rejected").WithCause(cause), wantKind: OutcomeDomain, wantStatus: 5},
+		{name: "domain zero becomes nonzero", outcome: Domain("validation", 0), wantKind: OutcomeDomain, wantStatus: 1},
+	} {
+		t.Run(test.name, func(t *testing.T) {
+			failing := newReporter(Streams{Out: &reporterTestWriter{err: outputErr}, Err: io.Discard})
+			_, _ = failing.Output().Write([]byte("partial"))
+			got := failing.finalize(test.outcome, nil)
+			if got.Kind != test.wantKind || got.Status != test.wantStatus {
+				t.Fatalf("outcome = %#v, want kind %q status %d", got, test.wantKind, test.wantStatus)
+			}
+			if got.Cause != nil && !errors.Is(got.Cause, cause) {
+				t.Fatalf("cause changed: %v", got.Cause)
+			}
+		})
+	}
+}
+
+func TestReporterDoesNotRetryFailedDiagnosticDestination(t *testing.T) {
+	diagnosticErr := errors.New("diagnostic sink failed")
+	destination := &reporterTestWriter{err: diagnosticErr}
+	reporter := newReporter(Streams{Err: destination})
+	_, _ = reporter.state.write(destinationDiagnostics, []byte("warning"))
+	outcome := reporter.finalize(Success(), nil)
+	if outcome.Kind != OutcomeOperational || outcome.Status != 1 || destination.writes != 1 {
+		t.Fatalf("outcome=%#v diagnostic writes=%d", outcome, destination.writes)
+	}
+	if !errors.Is(outcome.Presentation.Diagnostics.WriteError, diagnosticErr) {
+		t.Fatalf("diagnostic delivery = %#v", outcome.Presentation.Diagnostics)
+	}
+}
+
+func TestReporterUsesHealthyDiagnosticsAfterOutputRenderFailure(t *testing.T) {
+	var diagnostics bytes.Buffer
+	reporter := newReporter(Streams{Out: io.Discard, Err: &diagnostics})
+	renderErr := errors.New("report preparation failed")
+	_ = reporter.RenderOutput(func(io.Writer) error { return renderErr })
+	outcome := reporter.finalize(Success(), nil)
+	if outcome.Kind != OutcomeOperational || outcome.Status != 1 {
+		t.Fatalf("outcome = %#v", outcome)
+	}
+	if !errors.Is(outcome.Presentation.Output.RenderError, renderErr) || diagnostics.String() != "ERROR: Command failed.\n" {
+		t.Fatalf("presentation=%#v diagnostics=%q", outcome.Presentation, diagnostics.String())
+	}
+}
+
+func TestReporterTerminalDeliveryFailureIsRecordedWithoutRetry(t *testing.T) {
+	diagnosticErr := errors.New("terminal write failed")
+	destination := &reporterTestWriter{err: diagnosticErr}
+	reporter := newReporter(Streams{Err: destination})
+	outcome := reporter.finalize(Failure("explicit failure"), nil)
+	if outcome.Kind != OutcomeOperational || outcome.Status != 1 || destination.writes != 1 {
+		t.Fatalf("outcome=%#v diagnostic writes=%d", outcome, destination.writes)
+	}
+	if !errors.Is(outcome.Presentation.Diagnostics.WriteError, diagnosticErr) {
+		t.Fatalf("terminal delivery = %#v", outcome.Presentation.Diagnostics)
+	}
+}
+
+func TestReporterTerminalRenderFailureIsRecordedWithoutRetry(t *testing.T) {
+	var diagnostics bytes.Buffer
+	reporter := newReporter(Streams{Err: &diagnostics})
+	renderErr := errors.New("terminal renderer failed")
+	calls := 0
+	outcome := reporter.finalize(Failure("", func(io.Writer) error {
+		calls++
+		return renderErr
+	}), nil)
+	if outcome.Kind != OutcomeOperational || outcome.Status != 1 || calls != 1 || diagnostics.Len() != 0 {
+		t.Fatalf("outcome=%#v calls=%d output=%q", outcome, calls, diagnostics.String())
+	}
+	if !errors.Is(outcome.Presentation.Diagnostics.RenderError, renderErr) {
+		t.Fatalf("terminal presentation = %#v", outcome.Presentation.Diagnostics)
+	}
+}
+
+func TestReporterFinalizationClosesOutputAndDeferredHandles(t *testing.T) {
+	var output, diagnostics bytes.Buffer
+	reporter := newReporter(Streams{Out: &output, Err: &diagnostics})
+	writer := reporter.Output()
+	deferred := reporter.AtEnd()
+	_ = reporter.finalize(Success(), nil)
+	if n, err := writer.Write([]byte("late")); n != 0 || !errors.Is(err, ErrReporterClosed) {
+		t.Fatalf("late output = %d, %v", n, err)
+	}
+	if err := deferred.Warn("late warning"); !errors.Is(err, ErrReporterClosed) {
+		t.Fatalf("late deferred submission error = %v", err)
+	}
+	if output.Len() != 0 || diagnostics.Len() != 0 {
+		t.Fatalf("late output emitted: result=%q diagnostics=%q", output.String(), diagnostics.String())
+	}
+}