Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0

- Fixed a client ignoring queue pause, resume, or metadata changes until it restarted when the queue control notification was lost, as happens if it's sent while the client's notifier is reconnecting. Clients with a notifier now also check their queues' settings once a minute. [Issue #1579](https://github.com/riverqueue/river/issues/1579).
- Fixed the notifier never reconnecting when its connection went silent without an error, like after a dropped network path, because its health check ping had no timeout. The ping now times out after 10 seconds. [Issue #1579](https://github.com/riverqueue/river/issues/1579).
- Fixed maintenance services logging errors during normal shutdown or leadership loss, including `PeriodicJobEnqueuer` reporting `Error starting transaction: context canceled` when stopped during staggered startup. Genuine query timeouts and database failures are still logged, and periodic job transactions now roll back even after cancellation. [PR #1577](https://github.com/riverqueue/river/pull/1577).

## [0.51.0] - 2026-10-31

Expand Down
10 changes: 7 additions & 3 deletions internal/maintenance/job_cleaner.go
Original file line number Diff line number Diff line change
Expand Up @@ -145,7 +145,10 @@ func (s *JobCleaner) Start(ctx context.Context) error { //nolint:dupl
return nil
}

s.StaggerStart(ctx)
if !s.StaggerStart(ctx) {
stopped()
return nil
}

go func() {
started()
Expand All @@ -164,9 +167,10 @@ func (s *JobCleaner) Start(ctx context.Context) error { //nolint:dupl

res, err := s.runOnce(ctx)
if err != nil {
if !errors.Is(err, context.Canceled) {
s.Logger.ErrorContext(ctx, s.Name+": Error cleaning jobs", slog.String("error", err.Error()))
if ctx.Err() != nil {
return
}
s.Logger.ErrorContext(ctx, s.Name+": Error cleaning jobs", slog.String("error", err.Error()))
continue
}

Expand Down
10 changes: 7 additions & 3 deletions internal/maintenance/job_rescuer.go
Original file line number Diff line number Diff line change
Expand Up @@ -142,7 +142,10 @@ func (s *JobRescuer) Start(ctx context.Context) error {
return nil
}

s.StaggerStart(ctx)
if !s.StaggerStart(ctx) {
stopped()
return nil
}

go func() {
started()
Expand All @@ -161,9 +164,10 @@ func (s *JobRescuer) Start(ctx context.Context) error {

res, err := s.runOnce(ctx)
if err != nil {
if !errors.Is(err, context.Canceled) {
s.Logger.ErrorContext(ctx, s.Name+": Error rescuing jobs", slog.String("error", err.Error()))
if ctx.Err() != nil {
return
}
s.Logger.ErrorContext(ctx, s.Name+": Error rescuing jobs", slog.String("error", err.Error()))
continue
}

Expand Down
7 changes: 5 additions & 2 deletions internal/maintenance/job_scheduler.go
Original file line number Diff line number Diff line change
Expand Up @@ -107,13 +107,16 @@ func NewJobScheduler(archetype *baseservice.Archetype, config *JobSchedulerConfi
})
}

func (s *JobScheduler) Start(ctx context.Context) error {
func (s *JobScheduler) Start(ctx context.Context) error { //nolint:dupl
ctx, shouldStart, started, stopped := s.StartInit(ctx)
if !shouldStart {
return nil
}

s.StaggerStart(ctx)
if !s.StaggerStart(ctx) {
stopped()
return nil
}

go func() {
started()
Expand Down
41 changes: 31 additions & 10 deletions internal/maintenance/periodic_job_enqueuer.go
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@ import (
"github.com/riverqueue/river/rivershared/riversharedmaintenance"
"github.com/riverqueue/river/rivershared/startstop"
"github.com/riverqueue/river/rivershared/testsignal"
"github.com/riverqueue/river/rivershared/util/dbutil"
"github.com/riverqueue/river/rivershared/util/maputil"
"github.com/riverqueue/river/rivershared/util/sliceutil"
"github.com/riverqueue/river/rivershared/util/testutil"
Expand Down Expand Up @@ -319,7 +320,10 @@ func (s *PeriodicJobEnqueuer) Start(ctx context.Context) error {
return nil
}

s.StaggerStart(ctx)
if !s.StaggerStart(ctx) {
stopped()
return nil
}

var (
initialPeriodicJobs []*riverpilot.PeriodicJob
Expand Down Expand Up @@ -390,6 +394,10 @@ func (s *PeriodicJobEnqueuer) Start(ctx context.Context) error {
var lastHandleSeen rivertype.PeriodicJobHandle = -1 // so handle 0 is considered

validateInsertRunOnStartAndScheduleNewlyAdded := func() {
if ctx.Err() != nil {
return
}

var (
insertParamsMany []*rivertype.JobInsertParams
now = s.Time.Now()
Expand Down Expand Up @@ -532,38 +540,49 @@ func (s *PeriodicJobEnqueuer) Start(ctx context.Context) error {
}

func (s *PeriodicJobEnqueuer) insertBatch(ctx context.Context, insertParamsMany []*rivertype.JobInsertParams, periodicJobUpsertParams *riverpilot.PeriodicJobUpsertManyParams, periodicJobsToKeepAlive map[rivertype.PeriodicJobHandle]*PeriodicJob) {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤖 nit: the four if serviceCtx.Err() == nil { log } guards are the same decision made four times. The other services make it once by having runOnce return an error and logging in the loop. Optional, but insertBatch could do the same, which also removes the serviceCtx aliasing:

func (s *PeriodicJobEnqueuer) insertBatch(ctx context.Context, insertParamsMany []*rivertype.JobInsertParams, periodicJobUpsertParams *riverpilot.PeriodicJobUpsertManyParams, periodicJobsToKeepAlive map[rivertype.PeriodicJobHandle]*PeriodicJob) error {
	if len(insertParamsMany) < 1 && len(periodicJobUpsertParams.Jobs) < 1 {
		return nil
	}

	ctx, cancel := context.WithTimeout(ctx, riversharedmaintenance.TimeoutDefault)
	defer cancel()

	tx, err := s.exec.Begin(ctx)
	if err != nil {
		return fmt.Errorf("error starting transaction: %w", err)
	}
	defer dbutil.RollbackWithoutCancel(ctx, tx)

	if len(insertParamsMany) > 0 {
		if _, err := s.Config.Insert(ctx, tx, insertParamsMany); err != nil {
			return fmt.Errorf("error inserting %d periodic jobs: %w", len(insertParamsMany), err)
		}
	}

	if len(periodicJobUpsertParams.Jobs) > 0 {
		if _, err = s.Config.Pilot.PeriodicJobUpsertMany(ctx, tx, periodicJobUpsertParams); err != nil {
			return fmt.Errorf("error upserting %d periodic job next run times: %w", len(periodicJobUpsertParams.Jobs), err)
		}
	}

	if err := tx.Commit(ctx); err != nil {
		return fmt.Errorf("error committing transaction: %w", err)
	}

	// ... keepAlive marking and test signals unchanged ...
	return nil
}

Both call sites (inside validateInsertRunOnStartAndScheduleNewlyAdded and in the timer branch of the run loop) then use the same shape as the other services:

			if err := s.insertBatch(ctx, insertParamsMany, periodicJobUpsertParams, periodicJobsToKeepAlive); err != nil {
				if ctx.Err() != nil {
					return
				}
				s.Logger.ErrorContext(ctx, s.Name+": Error inserting periodic jobs", "error", err.Error())
			}

The ctx.Err() check at the top of validateInsertRunOnStartAndScheduleNewlyAdded should stay since it also skips calling user constructors. TestPeriodicJobEnqueuer_TransactionErrorLogging would need its log assertions adjusted to the single message plus the wrapped cause.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤖 Leaving this optional refactor out of this PR to keep the change focused. The existing transaction error tests cover cancellation, local timeouts, and database failures at each failure point.

if len(insertParamsMany) < 1 && len(periodicJobUpsertParams.Jobs) < 1 {
if ctx.Err() != nil || (len(insertParamsMany) < 1 && len(periodicJobUpsertParams.Jobs) < 1) {
return
}

// Check the service context when logging, so query timeouts still surface
// while shutdown errors (including driver-specific errors) stay quiet.
serviceCtx := ctx
ctx, cancel := context.WithTimeout(ctx, riversharedmaintenance.TimeoutDefault)
defer cancel()

tx, err := s.exec.Begin(ctx)
if err != nil {
s.Logger.ErrorContext(ctx, s.Name+": Error starting transaction", "error", err.Error())
if serviceCtx.Err() == nil {
s.Logger.ErrorContext(ctx, s.Name+": Error starting transaction", "error", err.Error())
}
return
}
defer tx.Rollback(ctx)
defer dbutil.RollbackWithoutCancel(ctx, tx)

if len(insertParamsMany) > 0 {
if _, err := s.Config.Insert(ctx, tx, insertParamsMany); err != nil {
s.Logger.ErrorContext(ctx, s.Name+": Error inserting periodic jobs",
"error", err.Error(), "num_jobs", len(insertParamsMany))
if serviceCtx.Err() == nil {
s.Logger.ErrorContext(ctx, s.Name+": Error inserting periodic jobs",
"error", err.Error(), "num_jobs", len(insertParamsMany))
}
return
}
}

if len(periodicJobUpsertParams.Jobs) > 0 {
if _, err = s.Config.Pilot.PeriodicJobUpsertMany(ctx, tx, periodicJobUpsertParams); err != nil {
s.Logger.ErrorContext(ctx, s.Name+": Error upserting periodic job next run times",
"error", err.Error(), "num_jobs", len(insertParamsMany), "num_next_run_at_upserts", len(periodicJobUpsertParams.Jobs))
if serviceCtx.Err() == nil {
s.Logger.ErrorContext(ctx, s.Name+": Error upserting periodic job next run times",
"error", err.Error(), "num_jobs", len(insertParamsMany), "num_next_run_at_upserts", len(periodicJobUpsertParams.Jobs))
}
return
}
}

if err := tx.Commit(ctx); err != nil {
s.Logger.ErrorContext(ctx, s.Name+": Error committing transaction", "error", err.Error())
if serviceCtx.Err() == nil {
s.Logger.ErrorContext(ctx, s.Name+": Error committing transaction", "error", err.Error())
}
return
}

Expand Down Expand Up @@ -649,7 +668,9 @@ func (s *PeriodicJobEnqueuer) periodicJobKeepAliveAndReapPeriodically(ctx contex
ID: ids,
Schema: s.Config.Schema,
}); err != nil {
s.Logger.ErrorContext(ctx, s.Name+": Error executing periodic job keep alive and reap", "error", err.Error())
if ctx.Err() == nil {
s.Logger.ErrorContext(ctx, s.Name+": Error executing periodic job keep alive and reap", "error", err.Error())
}
return
}
}
Expand Down
190 changes: 190 additions & 0 deletions internal/maintenance/periodic_job_enqueuer_shutdown_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,190 @@
package maintenance

import (
"bytes"
"context"
"errors"
"fmt"
"log/slog"
"os"
"testing"
"testing/synctest"
"time"

"github.com/stretchr/testify/require"

"github.com/riverqueue/river/riverdriver"
"github.com/riverqueue/river/rivershared/riverpilot"
"github.com/riverqueue/river/rivershared/riversharedtest"
"github.com/riverqueue/river/rivershared/testsignal"
"github.com/riverqueue/river/rivertype"
)

type periodicShutdownExecutor struct {
riverdriver.Executor

beginFunc func(context.Context) error
tx *periodicShutdownTx
}

func (e *periodicShutdownExecutor) Begin(ctx context.Context) (riverdriver.ExecutorTx, error) {
if err := e.beginFunc(ctx); err != nil {
return nil, err
}
return e.tx, nil
}

type periodicShutdownTx struct {
riverdriver.ExecutorTx

commitFunc func(context.Context) error
rollbackFunc func(context.Context) error
}

func (tx *periodicShutdownTx) Commit(ctx context.Context) error { return tx.commitFunc(ctx) }

func (tx *periodicShutdownTx) Rollback(ctx context.Context) error { return tx.rollbackFunc(ctx) }

func TestPeriodicJobEnqueuer_ShutdownDuringStagger(t *testing.T) {
t.Parallel()

for _, stopService := range []bool{false, true} {
t.Run(fmt.Sprintf("StopService=%t", stopService), func(t *testing.T) {
t.Parallel()

synctest.Test(t, func(t *testing.T) {
var logOutput bytes.Buffer
archetype := riversharedtest.BaseServiceArchetype(t)
archetype.Logger = slog.New(slog.NewTextHandler(&logOutput, &slog.HandlerOptions{Level: slog.LevelError}))
var beginCalls, constructorCalls, getAllCalls int
pilot := NewPilotPeriodicJobMock()
pilot.PeriodicJobGetAllMock = func(context.Context, riverdriver.Executor, *riverpilot.PeriodicJobGetAllParams) ([]*riverpilot.PeriodicJob, error) {
getAllCalls++
return nil, nil
}
svc, err := NewPeriodicJobEnqueuer(archetype, &PeriodicJobEnqueuerConfig{
PeriodicJobs: []*PeriodicJob{{
ConstructorFunc: func() (*rivertype.JobInsertParams, error) {
constructorCalls++
return &rivertype.JobInsertParams{}, nil
},
RunOnStart: true,
ScheduleFunc: func(now time.Time) time.Time { return now.Add(time.Hour) },
}},
Pilot: pilot,
}, &periodicShutdownExecutor{beginFunc: func(ctx context.Context) error {
beginCalls++
return ctx.Err()
}})
require.NoError(t, err)

ctx, cancel := context.WithCancel(context.Background())
defer cancel()
var startResult testsignal.TestSignal[error]
startResult.Init(t)
go func() { startResult.Signal(svc.Start(ctx)) }()
// Wait until Start is sleeping in the real stagger, without
// depending on its randomly selected duration.
synctest.Wait()
if stopService {
svc.Stop()
} else {
cancel()
}
err = startResult.WaitOrTimeout()
svc.Stop()
require.Empty(t, logOutput.String())
require.NoError(t, err)
require.Zero(t, beginCalls)
require.Zero(t, constructorCalls)
require.Zero(t, getAllCalls)
})
})
}
}

func TestPeriodicJobEnqueuer_TransactionErrorLogging(t *testing.T) {
t.Parallel()

for _, operation := range []string{"Begin", "Commit", "Insert", "Upsert"} {
t.Run(operation, func(t *testing.T) {
t.Parallel()

for _, outcome := range []string{"Canceled", "DatabaseError", "DriverErrorOnCancellation", "LocalTimeout", "ParentDeadline"} {
t.Run(outcome, func(t *testing.T) {
t.Parallel()

synctest.Test(t, func(t *testing.T) {
var logOutput bytes.Buffer
archetype := riversharedtest.BaseServiceArchetype(t)
archetype.Logger = slog.New(slog.NewTextHandler(&logOutput, &slog.HandlerOptions{Level: slog.LevelError}))
ctx, cancel := context.WithCancel(context.Background())
defer cancel()
if outcome == "ParentDeadline" {
var cancelDeadline context.CancelFunc
ctx, cancelDeadline = context.WithTimeout(ctx, time.Second)
defer cancelDeadline()
}
dbErr := errors.New("database failed")
operationFunc := func(queryCtx context.Context, name string) error {
if name != operation {
return nil
}
switch outcome {
case "Canceled":
cancel()
return fmt.Errorf("query interrupted: %w", queryCtx.Err())
case "DriverErrorOnCancellation":
cancel()
return fmt.Errorf("write failed: %w", os.ErrDeadlineExceeded)
case "LocalTimeout", "ParentDeadline":
<-queryCtx.Done()
return queryCtx.Err()
default:
return dbErr
}
}
rolledBack := false
exec := &periodicShutdownExecutor{
beginFunc: func(ctx context.Context) error { return operationFunc(ctx, "Begin") },
tx: &periodicShutdownTx{
commitFunc: func(ctx context.Context) error { return operationFunc(ctx, "Commit") },
rollbackFunc: func(ctx context.Context) error {
rolledBack = true
require.NoError(t, ctx.Err(), "rollback must survive query cancellation")
return nil
},
},
}
pilot := NewPilotPeriodicJobMock()
pilot.PeriodicJobUpsertManyMock = func(ctx context.Context, _ riverdriver.Executor, _ *riverpilot.PeriodicJobUpsertManyParams) ([]*riverpilot.PeriodicJob, error) {
return nil, operationFunc(ctx, "Upsert")
}
svc, err := NewPeriodicJobEnqueuer(archetype, &PeriodicJobEnqueuerConfig{
Insert: func(ctx context.Context, _ riverdriver.ExecutorTx, _ []*rivertype.JobInsertParams) ([]*rivertype.JobInsertResult, error) {
return nil, operationFunc(ctx, "Insert")
},
Pilot: pilot,
}, exec)
require.NoError(t, err)
svc.TestSignals.Init(t)
svc.insertBatch(ctx, []*rivertype.JobInsertParams{{}}, &riverpilot.PeriodicJobUpsertManyParams{
Jobs: []*riverpilot.PeriodicJobUpsertParams{{ID: "periodic"}},
}, nil)
switch outcome {
case "DatabaseError":
require.Contains(t, logOutput.String(), dbErr.Error())
case "LocalTimeout":
require.Contains(t, logOutput.String(), context.DeadlineExceeded.Error())
default:
require.Empty(t, logOutput.String())
}
require.Equal(t, operation != "Begin", rolledBack)
svc.TestSignals.InsertedJobs.RequireEmpty()
svc.TestSignals.PeriodicJobUpserted.RequireEmpty()
})
})
}
})
}
}
10 changes: 7 additions & 3 deletions internal/maintenance/queue_cleaner.go
Original file line number Diff line number Diff line change
Expand Up @@ -106,7 +106,10 @@ func (s *QueueCleaner) Start(ctx context.Context) error {
return nil
}

s.StaggerStart(ctx)
if !s.StaggerStart(ctx) {
stopped()
return nil
}

go func() {
started()
Expand All @@ -125,9 +128,10 @@ func (s *QueueCleaner) Start(ctx context.Context) error {

res, err := s.runOnce(ctx)
if err != nil {
if !errors.Is(err, context.Canceled) {
s.Logger.ErrorContext(ctx, s.Name+": Error cleaning queues", slog.String("error", err.Error()))
if ctx.Err() != nil {
return
}
s.Logger.ErrorContext(ctx, s.Name+": Error cleaning queues", slog.String("error", err.Error()))
continue
}

Expand Down
Loading
Loading