Files
honeyDueAPI/cmd/worker/main.go
T
Trey t 52bf1ff3c7
Backend CI / Test (push) Has been cancelled
Backend CI / Contract Tests (push) Has been cancelled
Backend CI / Lint (push) Has been cancelled
Backend CI / Secret Scanning (push) Has been cancelled
Backend CI / Build (push) Has been cancelled
perf(task): offload completion notification fan-out to Asynq worker
POST /api/task-completions/ was spending ~1.5-1.75s synchronously on
APNs push + SMTP email + B2 image fetches inside sendTaskCompletedNotification.
Per-user loop made it scale linearly with residence membership; one image
attached + one residence user is the 1.75s baseline observed in the live
honeydue-eli5-overview Grafana panel.

Replace the inline call (and the fire-and-forget goroutine in QuickComplete,
which violated the project's "no goroutines in handlers" rule) with an
Asynq job:

  - new task type notification:task_completed (worker/scheduler.go)
  - new payload {task_id, completion_id} — IDs only, worker re-reads
    canonical state from Postgres so concurrent edits between enqueue
    and dequeue are reflected
  - new HandleTaskCompletedNotification on jobs.Handler delegates to
    TaskService.SendTaskCompletedNotificationByID
  - new dispatchTaskCompletedNotification in task_service.go picks
    between enqueue (preferred) and inline (fallback) when Redis is
    unreachable or the enqueuer isn't wired (tests / local dev)

Other changes required to wire it up:

  - widen worker.NewTaskClient signature to accept asynq.RedisClientOpt
    so the file-mounted Redis password (audit HIGH-1) can be supplied;
    no prior callers, no breakage
  - extend worker.Enqueuer interface with EnqueueTaskCompletedNotification
  - add TaskEnqueuer field to router.Dependencies; wire from cmd/api/main.go
    with the standard typed-nil interface guard
  - wire a worker-side TaskService in cmd/worker/main.go so the handler
    can use the shared SendTaskCompletedNotificationByID implementation
    (storage service shared with the existing upload-cleanup wiring)

Expected impact on POST /api/task-completions/ p50:
  ~1.75s -> ~120-170ms (DB + tx + Asynq enqueue only)

Notifications still deliver; they just go via the worker instead of in
the request path. MaxRetry=3; "row not found" returns nil so a deleted
task/completion doesn't churn the retry loop.

All 31 test packages pass. No DB migrations.

Co-Authored-By: Claude Opus 4.7 <noreply@anthropic.com>
2026-06-03 09:34:52 -05:00

375 lines
14 KiB
Go

package main
import (
"context"
"net/http"
"os"
"os/signal"
"syscall"
"time"
"github.com/hibiken/asynq"
"github.com/redis/go-redis/v9"
"github.com/rs/zerolog/log"
"go.opentelemetry.io/otel/attribute"
"go.opentelemetry.io/otel/codes"
"go.opentelemetry.io/otel/trace"
"github.com/treytartt/honeydue-api/internal/config"
"github.com/treytartt/honeydue-api/internal/database"
"github.com/treytartt/honeydue-api/internal/monitoring"
"github.com/treytartt/honeydue-api/internal/prom"
"github.com/treytartt/honeydue-api/internal/push"
"github.com/treytartt/honeydue-api/internal/repositories"
"github.com/treytartt/honeydue-api/internal/services"
"github.com/treytartt/honeydue-api/internal/tracing"
"github.com/treytartt/honeydue-api/internal/worker"
"github.com/treytartt/honeydue-api/internal/worker/jobs"
"github.com/treytartt/honeydue-api/pkg/utils"
)
const workerHealthAddr = ":6060"
func main() {
// Initialize logger
utils.InitLogger(true)
// Load configuration
cfg, err := config.Load()
if err != nil {
log.Fatal().Err(err).Msg("Failed to load configuration")
}
// Check worker kill switch
if !cfg.Features.WorkerEnabled {
log.Warn().Msg("Worker disabled by FEATURE_WORKER_ENABLED=false — exiting")
os.Exit(0)
}
// Initialize OpenTelemetry tracing for the worker process. Same OTLP
// destination as the api; service.name distinguishes them in Jaeger.
// config.SecretValue (not os.Getenv) so file-mounted secrets resolve
// after audit F8 removed these from the process environment.
tracingShutdown, err := tracing.Init(context.Background(), tracing.Config{
ServiceName: "honeydue-worker",
Environment: workerDeploymentEnv(cfg.Server.Debug),
EndpointURL: config.SecretValue("OBS_TRACES_URL"),
BearerToken: config.SecretValue("OBS_INGEST_TOKEN"),
SampleRatio: tracing.SampleRatioFromEnv(),
})
if err != nil {
log.Error().Err(err).Msg("worker tracing init failed — continuing without traces")
}
defer func() {
shutdownCtx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
defer cancel()
if err := tracingShutdown(shutdownCtx); err != nil {
log.Warn().Err(err).Msg("worker tracing shutdown error")
}
}()
asynqTracer := tracing.Tracer("honeydue/worker/asynq")
// Initialize database
db, err := database.Connect(&cfg.Database, cfg.Server.Debug)
if err != nil {
log.Fatal().Err(err).Msg("Failed to connect to database")
}
log.Info().Msg("Connected to database")
// Get underlying *sql.DB for cleanup
sqlDB, _ := db.DB()
defer sqlDB.Close()
// Initialize push client (APNs + FCM)
var pushClient *push.Client
pushClient, err = push.NewClient(&cfg.Push, cfg.Features.PushEnabled)
if err != nil {
log.Warn().Err(err).Msg("Failed to initialize push client - push notifications disabled")
} else {
log.Info().
Bool("ios_enabled", pushClient.IsIOSEnabled()).
Bool("android_enabled", pushClient.IsAndroidEnabled()).
Msg("Push notification client initialized")
}
// Initialize email service (optional)
var emailService *services.EmailService
if cfg.Email.Host != "" {
emailService = services.NewEmailService(&cfg.Email, cfg.Features.EmailEnabled)
log.Info().Str("host", cfg.Email.Host).Msg("Email service initialized")
}
// Initialize notification service for actionable push notifications
notificationRepo := repositories.NewNotificationRepository(db)
notificationService := services.NewNotificationService(notificationRepo, pushClient)
log.Info().Msg("Notification service initialized")
// Parse Redis URL for Asynq
redisOpt, err := asynq.ParseRedisURI(cfg.Redis.URL)
if err != nil {
log.Fatal().Err(err).Msg("Failed to parse Redis URL")
}
// Audit HIGH-1: the Redis password is a file-mounted secret (REDIS_PASSWORD),
// not embedded in REDIS_URL — REDIS_URL travels in the honeydue-config
// ConfigMap. Apply the password onto the parsed opt so the Asynq server,
// inspector and monitoring client (all derived from redisOpt below)
// authenticate against a requirepass-protected Redis.
if cfg.Redis.Password != "" {
if clientOpt, ok := redisOpt.(asynq.RedisClientOpt); ok {
clientOpt.Password = cfg.Redis.Password
redisOpt = clientOpt
}
}
// Initialize monitoring service (if Redis is available)
var monitoringService *monitoring.Service
redisClientOpt, ok := redisOpt.(asynq.RedisClientOpt)
if ok {
redisClient := redis.NewClient(&redis.Options{
Addr: redisClientOpt.Addr,
Password: redisClientOpt.Password,
DB: redisClientOpt.DB,
})
// Verify Redis connection
if err := redisClient.Ping(context.Background()).Err(); err != nil {
log.Warn().Err(err).Msg("Failed to connect to Redis for monitoring - monitoring disabled")
} else {
monitoringService = monitoring.NewService(monitoring.Config{
Process: "worker",
RedisClient: redisClient,
DB: db, // Pass database for enable_monitoring setting sync
})
// Reinitialize logger with monitoring writer
utils.InitLoggerWithWriter(cfg.Server.Debug, monitoringService.LogWriter())
// Create Asynq inspector for queue statistics
inspector := asynq.NewInspector(redisOpt)
monitoringService.SetAsynqInspector(inspector)
// Start stats collection
monitoringService.Start()
defer monitoringService.Stop()
log.Info().
Bool("log_capture_enabled", monitoringService.IsEnabled()).
Msg("Monitoring service initialized")
}
}
// Create Asynq server
srv := asynq.NewServer(
redisOpt,
asynq.Config{
Concurrency: 10,
Queues: map[string]int{
"critical": 6,
"default": 3,
"low": 1,
},
ErrorHandler: asynq.ErrorHandlerFunc(func(ctx context.Context, task *asynq.Task, err error) {
log.Error().
Err(err).
Str("type", task.Type()).
Bytes("payload", task.Payload()).
Msg("Task processing failed")
}),
},
)
// Create job handler
jobHandler := jobs.NewHandler(db, pushClient, emailService, notificationService, cfg)
// Wire upload service for the pending_uploads cleanup cron AND share the
// underlying storage service with the TaskService below so the worker can
// load completion images for email embedding. Storage may be local-disk
// (no S3 backend), in which case the upload service stays nil and the
// cleanup handler no-ops. Cache is optional — the cleanup path doesn't
// rate-limit and works fine with a nil cache.
var sharedStorageService *services.StorageService
if storageService, sErr := services.NewStorageService(&cfg.Storage); sErr == nil {
sharedStorageService = storageService
if s3 := storageService.S3Backend(); s3 != nil {
pendingUploadRepo := repositories.NewPendingUploadRepository(db)
uploadService := services.NewUploadService(pendingUploadRepo, s3, &cfg.Storage, nil)
jobHandler.SetUploadService(uploadService)
}
} else {
log.Warn().Err(sErr).Msg("Failed to initialize storage service for upload cleanup; cleanup cron will no-op")
}
// Wire a TaskService for the task-completed notification handler. The
// worker re-creates this (vs. importing the api's wired instance) because
// each binary owns its own dependency graph. The handler is fully nil-safe
// — if any of the wired services are absent, the corresponding side of
// notification delivery (push or email) is skipped.
taskRepo := repositories.NewTaskRepository(db)
residenceRepo := repositories.NewResidenceRepository(db)
workerTaskService := services.NewTaskService(taskRepo, residenceRepo)
if notificationService != nil {
workerTaskService.SetNotificationService(notificationService)
}
if emailService != nil {
workerTaskService.SetEmailService(emailService)
}
if sharedStorageService != nil {
workerTaskService.SetStorageService(sharedStorageService)
}
jobHandler.SetTaskService(workerTaskService)
// Create Asynq mux and register handlers
mux := asynq.NewServeMux()
// Tracing + metrics middleware: every job runs inside a span and emits
// asynq_job_duration_seconds{task_type,result}.
mux.Use(asynqTracingMiddleware(asynqTracer))
mux.HandleFunc(jobs.TypeSmartReminder, jobHandler.HandleSmartReminder)
mux.HandleFunc(jobs.TypeDailyDigest, jobHandler.HandleDailyDigest)
mux.HandleFunc(jobs.TypeSendEmail, jobHandler.HandleSendEmail)
mux.HandleFunc(jobs.TypeSendPush, jobHandler.HandleSendPush)
mux.HandleFunc(jobs.TypeOnboardingEmails, jobHandler.HandleOnboardingEmails)
mux.HandleFunc(jobs.TypeReminderLogCleanup, jobHandler.HandleReminderLogCleanup)
mux.HandleFunc(jobs.TypeUploadCleanup, jobHandler.HandleUploadCleanup)
mux.HandleFunc(worker.TypeTaskCompletedNotification, jobHandler.HandleTaskCompletedNotification)
// Register email job handlers (welcome, verification, password reset, password changed)
if emailService != nil {
emailJobHandler := jobs.NewEmailJobHandler(emailService)
emailJobHandler.RegisterHandlers(mux)
}
// Start scheduler for periodic tasks
scheduler := asynq.NewScheduler(redisOpt, nil)
// Schedule smart reminder notifications (runs every hour to support per-user custom times)
// Replaces old task reminder and overdue reminder with frequency-aware system
// Uses TaskReminderLog to prevent duplicate notifications
if _, err := scheduler.Register("0 * * * *", asynq.NewTask(jobs.TypeSmartReminder, nil)); err != nil {
log.Fatal().Err(err).Msg("Failed to register smart reminder job")
}
log.Info().Str("cron", "0 * * * *").Int("default_hour", cfg.Worker.TaskReminderHour).Msg("Registered smart reminder job (runs hourly for per-user times)")
// Schedule daily digest (runs every hour to support per-user custom times)
// The job handler filters users based on their preferred notification hour
if _, err := scheduler.Register("0 * * * *", asynq.NewTask(jobs.TypeDailyDigest, nil)); err != nil {
log.Fatal().Err(err).Msg("Failed to register daily digest job")
}
log.Info().Str("cron", "0 * * * *").Int("default_hour", cfg.Worker.DailyNotifHour).Msg("Registered daily digest job (runs hourly for per-user times)")
// Schedule onboarding emails (runs daily at 10:00 AM UTC)
// Sends emails to users who haven't created residences or tasks after registration
if _, err := scheduler.Register("0 10 * * *", asynq.NewTask(jobs.TypeOnboardingEmails, nil)); err != nil {
log.Fatal().Err(err).Msg("Failed to register onboarding emails job")
}
log.Info().Str("cron", "0 10 * * *").Msg("Registered onboarding emails job (runs daily at 10:00 AM UTC)")
// Schedule reminder log cleanup (runs daily at 3:00 AM UTC)
// Removes reminder logs older than 90 days to prevent table bloat
if _, err := scheduler.Register("0 3 * * *", asynq.NewTask(jobs.TypeReminderLogCleanup, nil)); err != nil {
log.Fatal().Err(err).Msg("Failed to register reminder log cleanup job")
}
log.Info().Str("cron", "0 3 * * *").Msg("Registered reminder log cleanup job (runs daily at 3:00 AM UTC)")
// Schedule pending_uploads cleanup (hourly at :30 to avoid colliding with
// the top-of-hour reminder + digest crons). Reaps unclaimed expired
// upload sessions; the B2 bucket lifecycle (7 days on uploads/ prefix)
// is the backstop if this worker is offline for an extended period.
if _, err := scheduler.Register("30 * * * *", asynq.NewTask(jobs.TypeUploadCleanup, nil)); err != nil {
log.Fatal().Err(err).Msg("Failed to register upload cleanup job")
}
log.Info().Str("cron", "30 * * * *").Msg("Registered pending_uploads cleanup job (runs hourly)")
// Handle graceful shutdown
quit := make(chan os.Signal, 1)
signal.Notify(quit, syscall.SIGINT, syscall.SIGTERM)
// Health server (for container healthchecks; not externally published)
healthMux := http.NewServeMux()
healthMux.HandleFunc("/health", func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "application/json")
w.WriteHeader(http.StatusOK)
_, _ = w.Write([]byte(`{"status":"ok"}`))
})
healthSrv := &http.Server{
Addr: workerHealthAddr,
Handler: healthMux,
ReadHeaderTimeout: 5 * time.Second,
}
go func() {
log.Info().Str("addr", workerHealthAddr).Msg("Health server listening")
if err := healthSrv.ListenAndServe(); err != nil && err != http.ErrServerClosed {
log.Warn().Err(err).Msg("Health server terminated")
}
}()
// Start scheduler in goroutine
go func() {
if err := scheduler.Run(); err != nil {
log.Fatal().Err(err).Msg("Failed to start scheduler")
}
}()
// Start worker server in goroutine
go func() {
log.Info().Msg("Starting worker server...")
if err := srv.Run(mux); err != nil {
log.Fatal().Err(err).Msg("Failed to start worker server")
}
}()
<-quit
log.Info().Msg("Shutting down worker...")
// Graceful shutdown
shutdownCtx, shutdownCancel := context.WithTimeout(context.Background(), 5*time.Second)
defer shutdownCancel()
_ = healthSrv.Shutdown(shutdownCtx)
srv.Shutdown()
scheduler.Shutdown()
log.Info().Msg("Worker stopped")
}
// asynqTracingMiddleware returns an asynq.MiddlewareFunc that opens a span
// per task execution and records asynq_job_duration_seconds. Span attrs
// include task type, queue, retry count, and the result outcome.
func asynqTracingMiddleware(tracer trace.Tracer) asynq.MiddlewareFunc {
return func(next asynq.Handler) asynq.Handler {
return asynq.HandlerFunc(func(ctx context.Context, t *asynq.Task) error {
ctx, span := tracer.Start(ctx, "asynq.handle:"+t.Type(),
trace.WithAttributes(
attribute.String("asynq.task_type", t.Type()),
attribute.Int("asynq.payload_bytes", len(t.Payload())),
),
)
defer span.End()
start := time.Now()
err := next.ProcessTask(ctx, t)
dur := time.Since(start)
result := "ok"
if err != nil {
result = "error"
span.SetStatus(codes.Error, err.Error())
span.RecordError(err)
}
span.SetAttributes(attribute.String("asynq.result", result))
prom.ObserveAsynqJob(t.Type(), result, dur)
return err
})
}
}
// workerDeploymentEnv mirrors deploymentEnvironment in cmd/api/main.go.
func workerDeploymentEnv(debug bool) string {
if env := os.Getenv("DEPLOYMENT_ENVIRONMENT"); env != "" {
return env
}
if debug {
return "dev"
}
return "prod"
}