Compare commits

..

4 Commits

Author SHA1 Message Date
2eead05c34 feat: expirar jobs stuck com status timeout
Adiciona mecanismo de expiração periódica para jobs que ficam presos
nos status received ou processing além de um threshold configurável.

- models: novo status StatusTimeout
- store: migration v2 com índice em jobs(status); método ExpireStuck
  que faz UPDATE atômico para os status alvo anteriores ao threshold
- expirer: novo pacote com goroutine periódica que chama ExpireStuck
  e loga WARN quando algum job é expirado
- config: campos JobTimeoutMinutes (default 120) e
  ExpirerIntervalMinutes (default 10), lidos via env vars
  JOB_TIMEOUT_MINUTES e EXPIRER_INTERVAL_MINUTES
- main: instancia e inicia o Expirer no startup
- dashboard: card Timeout com contagem; badge neutral na tabela de jobs
2026-07-07 08:43:33 -03:00
7e5f4cb155 feat(worker): adicionar logs estruturados ao longo do ciclo do job
- Enriquecer logger com artist e album após carregar o job do banco
- Logar início do job com path e contagem de FLACs encontrados
- Logar cada arquivo antes de chamar o ffmpeg
- Emitir Error('job failed') ou Info('job completed') em finishJob,
  garantindo que todo encerramento gere entrada na tabela de logs
2026-07-07 08:43:26 -03:00
708dc5fda9 fix: use context.Background() ao enfileirar jobs
O contexto da requisição HTTP era passado para o Enqueue, causando
'context canceled' quando a conexão encerrava antes do INSERT no
SQLite completar. Jobs devem ser persistidos independentemente do
ciclo de vida da requisição.
2026-07-07 08:43:20 -03:00
e60ec521e1 fix(ntfy): migrate to JSON publishing to fix 400 invalid JSON error
POST to root / with application/json body instead of /<topic>
with plain-text headers. Prevents ntfy error 40024 when ErrorMsg
contains JSON content.
2026-07-07 08:33:27 -03:00
14 changed files with 266 additions and 92 deletions

View File

@ -12,6 +12,7 @@ import (
"time" "time"
"coda/internal/config" "coda/internal/config"
"coda/internal/expirer"
"coda/internal/jobs" "coda/internal/jobs"
"coda/internal/lidarr" "coda/internal/lidarr"
"coda/internal/logger" "coda/internal/logger"
@ -74,6 +75,13 @@ func main() {
} }
pool.Start(ctx) pool.Start(ctx)
exp := expirer.New(
st.Jobs,
time.Duration(envCfg.JobTimeoutMinutes)*time.Minute,
time.Duration(envCfg.ExpirerIntervalMinutes)*time.Minute,
)
exp.Start(ctx)
r := chi.NewRouter() r := chi.NewRouter()
r.Use(middleware.RequestID) r.Use(middleware.RequestID)
r.Use(middleware.Recoverer) r.Use(middleware.Recoverer)

View File

@ -68,6 +68,8 @@ type Config struct {
NtfyURL string NtfyURL string
NtfyTopic string NtfyTopic string
NtfyToken string NtfyToken string
JobTimeoutMinutes int
ExpirerIntervalMinutes int
} }
func Load() (*Config, error) { func Load() (*Config, error) {
@ -102,6 +104,8 @@ func buildConfig(overrides map[string]string) *Config {
NtfyURL: mergeString(overrides, "NTFY_URL", ""), NtfyURL: mergeString(overrides, "NTFY_URL", ""),
NtfyTopic: mergeString(overrides, "NTFY_TOPIC", ""), NtfyTopic: mergeString(overrides, "NTFY_TOPIC", ""),
NtfyToken: mergeString(overrides, "NTFY_TOKEN", ""), NtfyToken: mergeString(overrides, "NTFY_TOKEN", ""),
JobTimeoutMinutes: mergeInt(overrides, "JOB_TIMEOUT_MINUTES", 120),
ExpirerIntervalMinutes: mergeInt(overrides, "EXPIRER_INTERVAL_MINUTES", 10),
} }
} }

View File

@ -0,0 +1,57 @@
package expirer
import (
"context"
"log/slog"
"time"
"coda/internal/models"
)
type JobExpirer interface {
ExpireStuck(ctx context.Context, statuses []models.JobStatus, olderThan time.Duration) (int, error)
}
type Expirer struct {
jobs JobExpirer
timeout time.Duration
interval time.Duration
}
func New(jobs JobExpirer, timeout, interval time.Duration) *Expirer {
return &Expirer{
jobs: jobs,
timeout: timeout,
interval: interval,
}
}
func (e *Expirer) Start(ctx context.Context) {
go e.run(ctx)
}
func (e *Expirer) run(ctx context.Context) {
ticker := time.NewTicker(e.interval)
defer ticker.Stop()
for {
select {
case <-ctx.Done():
return
case <-ticker.C:
e.expire(ctx)
}
}
}
func (e *Expirer) expire(ctx context.Context) {
statuses := []models.JobStatus{models.StatusReceived, models.StatusProcessing}
n, err := e.jobs.ExpireStuck(ctx, statuses, e.timeout)
if err != nil {
slog.Error("expirer: failed to expire stuck jobs", "error", err)
return
}
if n > 0 {
slog.Warn("expirer: expired stuck jobs", "count", n, "timeout", e.timeout)
}
}

View File

@ -9,6 +9,7 @@ const (
StatusProcessing JobStatus = "processing" StatusProcessing JobStatus = "processing"
StatusDone JobStatus = "done" StatusDone JobStatus = "done"
StatusError JobStatus = "error" StatusError JobStatus = "error"
StatusTimeout JobStatus = "timeout"
) )
type JobSource string type JobSource string

View File

@ -20,12 +20,7 @@ const (
maxResponseBytes = 4096 maxResponseBytes = 4096
) )
type Client struct { type payload struct {
cfg *config.Service
hc *http.Client
}
type message struct {
Topic string `json:"topic"` Topic string `json:"topic"`
Title string `json:"title"` Title string `json:"title"`
Message string `json:"message"` Message string `json:"message"`
@ -33,6 +28,11 @@ type message struct {
Tags []string `json:"tags"` Tags []string `json:"tags"`
} }
type Client struct {
cfg *config.Service
hc *http.Client
}
func New(cfg *config.Service) *Client { func New(cfg *config.Service) *Client {
return &Client{ return &Client{
cfg: cfg, cfg: cfg,
@ -62,13 +62,14 @@ func (c *Client) Notify(ctx context.Context, job *models.Job) error {
return nil return nil
} }
msg := buildMessage(job, cfg.NtfyTopic) p := buildPayload(cfg.NtfyTopic, job)
body, err := json.Marshal(msg)
body, err := json.Marshal(p)
if err != nil { if err != nil {
return fmt.Errorf("marshal notification: %w", err) return fmt.Errorf("marshal ntfy payload: %w", err)
} }
endpoint, err := rootURL(cfg.NtfyURL) endpoint, err := publishURL(cfg.NtfyURL)
if err != nil { if err != nil {
return err return err
} }
@ -97,9 +98,9 @@ func (c *Client) Notify(ctx context.Context, job *models.Job) error {
return fmt.Errorf("ntfy returned %d: %s", resp.StatusCode, string(respBody)) return fmt.Errorf("ntfy returned %d: %s", resp.StatusCode, string(respBody))
} }
func buildMessage(job *models.Job, topic string) message { func buildPayload(topic string, job *models.Job) payload {
if job.Status == models.StatusError { if job.Status == models.StatusError {
return message{ return payload{
Topic: topic, Topic: topic,
Title: fmt.Sprintf("Coda: %s - %s failed", job.Artist, job.Album), Title: fmt.Sprintf("Coda: %s - %s failed", job.Artist, job.Album),
Message: job.ErrorMsg, Message: job.ErrorMsg,
@ -107,8 +108,7 @@ func buildMessage(job *models.Job, topic string) message {
Tags: []string{"x"}, Tags: []string{"x"},
} }
} }
return payload{
return message{
Topic: topic, Topic: topic,
Title: fmt.Sprintf("Coda: %s - %s completed", job.Artist, job.Album), Title: fmt.Sprintf("Coda: %s - %s completed", job.Artist, job.Album),
Message: "Conversion completed successfully", Message: "Conversion completed successfully",
@ -117,7 +117,7 @@ func buildMessage(job *models.Job, topic string) message {
} }
} }
func rootURL(baseURL string) (string, error) { func publishURL(baseURL string) (string, error) {
u, err := url.Parse(baseURL) u, err := url.Parse(baseURL)
if err != nil { if err != nil {
return "", fmt.Errorf("parse ntfy URL: %w", err) return "", fmt.Errorf("parse ntfy URL: %w", err)

View File

@ -3,6 +3,7 @@ package ntfy
import ( import (
"context" "context"
"encoding/json" "encoding/json"
"io"
"net/http" "net/http"
"net/http/httptest" "net/http/httptest"
"sync/atomic" "sync/atomic"
@ -46,11 +47,25 @@ func newClientWithOverrides(t *testing.T, overrides map[string]string) *Client {
return New(svc) return New(svc)
} }
func readPayload(t *testing.T, r *http.Request) payload {
t.Helper()
b, err := io.ReadAll(r.Body)
if err != nil {
t.Fatalf("read body: %v", err)
}
var p payload
if err := json.Unmarshal(b, &p); err != nil {
t.Fatalf("unmarshal payload: %v (body: %s)", err, string(b))
}
return p
}
func TestNotifySendsDoneMessage(t *testing.T) { func TestNotifySendsDoneMessage(t *testing.T) {
var ( var (
gotMethod string gotMethod string
gotPath string gotPath string
gotBody message gotContentType string
gotPayload payload
wasCalled atomic.Bool wasCalled atomic.Bool
) )
@ -58,9 +73,8 @@ func TestNotifySendsDoneMessage(t *testing.T) {
wasCalled.Store(true) wasCalled.Store(true)
gotMethod = r.Method gotMethod = r.Method
gotPath = r.URL.Path gotPath = r.URL.Path
if err := json.NewDecoder(r.Body).Decode(&gotBody); err != nil { gotContentType = r.Header.Get("Content-Type")
t.Errorf("decode body: %v", err) gotPayload = readPayload(t, r)
}
w.WriteHeader(http.StatusOK) w.WriteHeader(http.StatusOK)
})) }))
defer srv.Close() defer srv.Close()
@ -91,30 +105,31 @@ func TestNotifySendsDoneMessage(t *testing.T) {
if gotPath != "/" { if gotPath != "/" {
t.Errorf("path = %q, want /", gotPath) t.Errorf("path = %q, want /", gotPath)
} }
if gotBody.Topic != "coda" { if gotContentType != "application/json" {
t.Errorf("topic = %q, want coda", gotBody.Topic) t.Errorf("Content-Type = %q, want application/json", gotContentType)
} }
if gotBody.Title != "Coda: Artist - Album completed" { if gotPayload.Topic != "coda" {
t.Errorf("title = %q, want artist and album completed title", gotBody.Title) t.Errorf("topic = %q, want coda", gotPayload.Topic)
} }
if gotBody.Message != "Conversion completed successfully" { if gotPayload.Title != "Coda: Artist - Album completed" {
t.Errorf("message = %q, want success message", gotBody.Message) t.Errorf("title = %q, want completed title", gotPayload.Title)
} }
if gotBody.Priority != "default" { if gotPayload.Message != "Conversion completed successfully" {
t.Errorf("priority = %q, want default", gotBody.Priority) t.Errorf("message = %q, want success message", gotPayload.Message)
} }
if len(gotBody.Tags) != 1 || gotBody.Tags[0] != "white_check_mark" { if gotPayload.Priority != "default" {
t.Errorf("tags = %v, want [white_check_mark]", gotBody.Tags) t.Errorf("priority = %q, want default", gotPayload.Priority)
}
if len(gotPayload.Tags) != 1 || gotPayload.Tags[0] != "white_check_mark" {
t.Errorf("tags = %v, want [white_check_mark]", gotPayload.Tags)
} }
} }
func TestNotifySendsErrorMessage(t *testing.T) { func TestNotifySendsErrorMessage(t *testing.T) {
var gotBody message var gotPayload payload
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
if err := json.NewDecoder(r.Body).Decode(&gotBody); err != nil { gotPayload = readPayload(t, r)
t.Errorf("decode body: %v", err)
}
w.WriteHeader(http.StatusOK) w.WriteHeader(http.StatusOK)
})) }))
defer srv.Close() defer srv.Close()
@ -137,17 +152,50 @@ func TestNotifySendsErrorMessage(t *testing.T) {
t.Fatalf("Notify: %v", err) t.Fatalf("Notify: %v", err)
} }
if gotBody.Title != "Coda: Artist - Album failed" { if gotPayload.Title != "Coda: Artist - Album failed" {
t.Errorf("title = %q, want artist and album failed title", gotBody.Title) t.Errorf("title = %q, want failed title", gotPayload.Title)
} }
if gotBody.Message != "validation failed" { if gotPayload.Message != "validation failed" {
t.Errorf("message = %q, want error message", gotBody.Message) t.Errorf("message = %q, want error message", gotPayload.Message)
} }
if gotBody.Priority != "high" { if gotPayload.Priority != "high" {
t.Errorf("priority = %q, want high", gotBody.Priority) t.Errorf("priority = %q, want high", gotPayload.Priority)
} }
if len(gotBody.Tags) != 1 || gotBody.Tags[0] != "x" { if len(gotPayload.Tags) != 1 || gotPayload.Tags[0] != "x" {
t.Errorf("tags = %v, want [x]", gotBody.Tags) t.Errorf("tags = %v, want [x]", gotPayload.Tags)
}
}
func TestNotifyErrorMsgWithJSONContent(t *testing.T) {
var gotPayload payload
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
gotPayload = readPayload(t, r)
w.WriteHeader(http.StatusOK)
}))
defer srv.Close()
c := newClientWithOverrides(t, map[string]string{
"DRY_RUN": "false",
"NTFY_ENABLED": "true",
"NTFY_URL": srv.URL,
"NTFY_TOPIC": "coda",
})
jsonErr := `{"error": "ffmpeg exit code 1", "details": "no such file"}`
err := c.Notify(context.Background(), &models.Job{
ID: "job-1",
Artist: "Artist",
Album: "Album",
Status: models.StatusError,
ErrorMsg: jsonErr,
})
if err != nil {
t.Fatalf("Notify: %v", err)
}
if gotPayload.Message != jsonErr {
t.Errorf("message = %q, want raw JSON string as message", gotPayload.Message)
} }
} }

View File

@ -4,6 +4,7 @@ import (
"context" "context"
"database/sql" "database/sql"
"fmt" "fmt"
"strings"
"time" "time"
"coda/internal/models" "coda/internal/models"
@ -145,3 +146,35 @@ func (r *JobRepository) Finish(ctx context.Context, id string, status models.Job
} }
return nil return nil
} }
func (r *JobRepository) ExpireStuck(ctx context.Context, statuses []models.JobStatus, olderThan time.Duration) (int, error) {
if len(statuses) == 0 {
return 0, nil
}
placeholders := make([]string, len(statuses))
args := make([]any, 0, len(statuses)+1)
for i, status := range statuses {
placeholders[i] = "?"
args = append(args, status)
}
args = append(args, time.Now().UTC().Add(-olderThan))
query := fmt.Sprintf(
`UPDATE jobs SET status = ?, finished_at = ?, error_msg = ? WHERE status IN (%s) AND created_at < ?`,
strings.Join(placeholders, ","),
)
finalArgs := []any{models.StatusTimeout, time.Now().UTC(), "job timed out"}
finalArgs = append(finalArgs, args...)
result, err := r.db.ExecContext(ctx, query, finalArgs...)
if err != nil {
return 0, fmt.Errorf("expire stuck jobs: %w", err)
}
rows, err := result.RowsAffected()
if err != nil {
return 0, fmt.Errorf("rows affected: %w", err)
}
return int(rows), nil
}

View File

@ -59,6 +59,12 @@ func migrate(ctx context.Context, db *sql.DB) error {
)`, )`,
}, },
}, },
{
version: 2,
sql: []string{
`CREATE INDEX IF NOT EXISTS idx_jobs_status ON jobs(status)`,
},
},
} }
for _, m := range migrations { for _, m := range migrations {

View File

@ -23,6 +23,7 @@ type dashboardData struct {
ProcessingCount int ProcessingCount int
DoneCount int DoneCount int
ErrorCount int ErrorCount int
TimeoutCount int
} }
func (h *Handler) Dashboard(w http.ResponseWriter, r *http.Request) { func (h *Handler) Dashboard(w http.ResponseWriter, r *http.Request) {
@ -45,6 +46,7 @@ func (h *Handler) Dashboard(w http.ResponseWriter, r *http.Request) {
dd.ProcessingCount = h.jobCount(ctx, models.StatusProcessing) dd.ProcessingCount = h.jobCount(ctx, models.StatusProcessing)
dd.DoneCount = h.jobCount(ctx, models.StatusDone) dd.DoneCount = h.jobCount(ctx, models.StatusDone)
dd.ErrorCount = h.jobCount(ctx, models.StatusError) dd.ErrorCount = h.jobCount(ctx, models.StatusError)
dd.TimeoutCount = h.jobCount(ctx, models.StatusTimeout)
h.render.Render(w, "dashboard.html", dd) h.render.Render(w, "dashboard.html", dd)
} }
@ -64,6 +66,7 @@ func (h *Handler) Status(w http.ResponseWriter, r *http.Request) {
ProcessingCount: h.jobCount(ctx, models.StatusProcessing), ProcessingCount: h.jobCount(ctx, models.StatusProcessing),
DoneCount: h.jobCount(ctx, models.StatusDone), DoneCount: h.jobCount(ctx, models.StatusDone),
ErrorCount: h.jobCount(ctx, models.StatusError), ErrorCount: h.jobCount(ctx, models.StatusError),
TimeoutCount: h.jobCount(ctx, models.StatusTimeout),
} }
h.render.Render(w, "status.html", dd) h.render.Render(w, "status.html", dd)

View File

@ -1,6 +1,7 @@
package web package web
import ( import (
"context"
"encoding/json" "encoding/json"
"log/slog" "log/slog"
"net/http" "net/http"
@ -107,7 +108,7 @@ func (h *Handler) LibraryConvert(w http.ResponseWriter, r *http.Request) {
album := filepath.Base(absPath) album := filepath.Base(absPath)
artist := filepath.Base(filepath.Dir(absPath)) artist := filepath.Base(filepath.Dir(absPath))
id, err := h.enqueuer.Enqueue(r.Context(), jobs.EnqueueInput{ id, err := h.enqueuer.Enqueue(context.Background(), jobs.EnqueueInput{
Artist: artist, Artist: artist,
Album: album, Album: album,
Path: absPath, Path: absPath,

View File

@ -81,6 +81,8 @@ func statusBadge(level string) template.HTML {
return template.HTML(`<span class="badge badge-error">` + level + `</span>`) return template.HTML(`<span class="badge badge-error">` + level + `</span>`)
case "received": case "received":
return template.HTML(`<span class="badge badge-info">` + level + `</span>`) return template.HTML(`<span class="badge badge-info">` + level + `</span>`)
case "timeout":
return template.HTML(`<span class="badge badge-neutral">` + level + `</span>`)
default: default:
return template.HTML(level) return template.HTML(level)
} }

View File

@ -1,6 +1,7 @@
package webhook package webhook
import ( import (
"context"
"encoding/json" "encoding/json"
"fmt" "fmt"
"log/slog" "log/slog"
@ -89,7 +90,7 @@ func (h *Handler) Handle(w http.ResponseWriter, r *http.Request) {
return return
} }
id, err := h.enqueuer.Enqueue(r.Context(), jobs.EnqueueInput{ id, err := h.enqueuer.Enqueue(context.Background(), jobs.EnqueueInput{
Artist: payload.Artist.Name, Artist: payload.Artist.Name,
Album: payload.Album.Title, Album: payload.Album.Title,
Path: resolved, Path: resolved,

View File

@ -120,6 +120,8 @@ func (p *Pool) process(ctx context.Context, id string) {
return return
} }
logger = slog.With("job_id", job.ID, "artist", job.Artist, "album", job.Album)
flacFiles, err := filepath.Glob(filepath.Join(job.Path, "*.flac")) flacFiles, err := filepath.Glob(filepath.Join(job.Path, "*.flac"))
if err != nil { if err != nil {
p.finishJob(ctx, logger, job, models.StatusError, time.Since(startedAt), fmt.Sprintf("glob flac files: %v", err)) p.finishJob(ctx, logger, job, models.StatusError, time.Since(startedAt), fmt.Sprintf("glob flac files: %v", err))
@ -137,8 +139,11 @@ func (p *Pool) process(ctx context.Context, id string) {
return return
} }
logger.Info("starting job", "path", job.Path, "flac_count", len(flacFiles))
var mp3Paths []string var mp3Paths []string
for _, flac := range flacFiles { for _, flac := range flacFiles {
logger.Info("converting file", "file", filepath.Base(flac))
mp3, err := p.transcoder.ConvertFile(ctx, flac) mp3, err := p.transcoder.ConvertFile(ctx, flac)
if err != nil { if err != nil {
p.finishJob(ctx, logger, job, models.StatusError, time.Since(startedAt), fmt.Sprintf("convert %s: %v", filepath.Base(flac), err)) p.finishJob(ctx, logger, job, models.StatusError, time.Since(startedAt), fmt.Sprintf("convert %s: %v", filepath.Base(flac), err))
@ -165,13 +170,6 @@ func (p *Pool) process(ctx context.Context, id string) {
logger.Warn("rescanner failed", "error", err) logger.Warn("rescanner failed", "error", err)
} }
} }
logger.Info("job completed",
"artist", job.Artist,
"album", job.Album,
"files", len(flacFiles),
"duration_ms", time.Since(startedAt).Milliseconds(),
)
} }
p.finishJob(ctx, logger, job, models.StatusDone, time.Since(startedAt), "") p.finishJob(ctx, logger, job, models.StatusDone, time.Since(startedAt), "")
@ -193,4 +191,10 @@ func (p *Pool) finishJob(ctx context.Context, logger *slog.Logger, job *models.J
if err := p.store.Jobs.Finish(ctx, job.ID, status, durationMs, errMsg); err != nil { if err := p.store.Jobs.Finish(ctx, job.ID, status, durationMs, errMsg); err != nil {
logger.Error("failed to finish job", "error", err) logger.Error("failed to finish job", "error", err)
} }
if status == models.StatusError {
logger.Error("job failed", "error_msg", errMsg, "duration_ms", durationMs)
} else {
logger.Info("job completed", "duration_ms", durationMs)
}
} }

View File

@ -31,7 +31,7 @@
</div> </div>
</div> </div>
<div class="grid grid-cols-2 md:grid-cols-4 gap-4"> <div class="grid grid-cols-2 md:grid-cols-5 gap-4">
<div class="card bg-base-100 shadow"> <div class="card bg-base-100 shadow">
<div class="card-body"> <div class="card-body">
<h2 class="card-title">Received</h2> <h2 class="card-title">Received</h2>
@ -56,6 +56,12 @@
<p class="text-4xl font-bold text-error">{{ .ErrorCount }}</p> <p class="text-4xl font-bold text-error">{{ .ErrorCount }}</p>
</div> </div>
</div> </div>
<div class="card bg-base-100 shadow">
<div class="card-body">
<h2 class="card-title">Timeout</h2>
<p class="text-4xl font-bold text-neutral">{{ .TimeoutCount }}</p>
</div>
</div>
</div> </div>
<div class="card bg-base-100 shadow"> <div class="card bg-base-100 shadow">