feat(cron): add execution lifecycle logging (#1185)

- Log job start with name, id, schedule kind, and channel
- Log job completion with duration and next run time
- Log job errors with duration and error message
- Helps diagnose scheduler stalls and connection issues
This commit is contained in:
fishtrees 2026-03-06 20:46:52 +08:00 committed by GitHub
parent 7f6d95c026
commit 1945436dd4
No known key found for this signature in database
GPG key ID: B5690EEEBB952194

View file

@ -190,14 +190,21 @@ func (cs *CronService) executeJobByID(jobID string) {
cs.mu.RUnlock() cs.mu.RUnlock()
if callbackJob == nil { if callbackJob == nil {
log.Printf("[cron] job %s not found, skipping", jobID)
return return
} }
// Log job execution start
log.Printf("[cron] ▶ executing job '%s' (id: %s, schedule: %s, channel: %s)",
callbackJob.Name, jobID, callbackJob.Schedule.Kind, callbackJob.Payload.Channel)
var err error var err error
if cs.onJob != nil { if cs.onJob != nil {
_, err = cs.onJob(callbackJob) _, err = cs.onJob(callbackJob)
} }
execDuration := time.Now().UnixMilli() - startTime
// Now acquire lock to update state // Now acquire lock to update state
cs.mu.Lock() cs.mu.Lock()
defer cs.mu.Unlock() defer cs.mu.Unlock()
@ -220,22 +227,35 @@ func (cs *CronService) executeJobByID(jobID string) {
if err != nil { if err != nil {
job.State.LastStatus = "error" job.State.LastStatus = "error"
job.State.LastError = err.Error() job.State.LastError = err.Error()
log.Printf("[cron] ✗ job '%s' failed after %dms: %v", job.Name, execDuration, err)
} else { } else {
job.State.LastStatus = "ok" job.State.LastStatus = "ok"
job.State.LastError = "" job.State.LastError = ""
} }
// Compute next run time // Compute next run time
var nextRunStr string
if job.Schedule.Kind == "at" { if job.Schedule.Kind == "at" {
if job.DeleteAfterRun { if job.DeleteAfterRun {
cs.removeJobUnsafe(job.ID) cs.removeJobUnsafe(job.ID)
nextRunStr = "(deleted)"
} else { } else {
job.Enabled = false job.Enabled = false
job.State.NextRunAtMS = nil job.State.NextRunAtMS = nil
nextRunStr = "(disabled)"
} }
} else { } else {
nextRun := cs.computeNextRun(&job.Schedule, time.Now().UnixMilli()) nextRun := cs.computeNextRun(&job.Schedule, time.Now().UnixMilli())
job.State.NextRunAtMS = nextRun job.State.NextRunAtMS = nextRun
if nextRun != nil {
nextRunStr = time.UnixMilli(*nextRun).Format("2006-01-02 15:04:05")
} else {
nextRunStr = "(none)"
}
}
if err == nil {
log.Printf("[cron] ✓ job '%s' completed in %dms, next run: %s", job.Name, execDuration, nextRunStr)
} }
if err := cs.saveStoreUnsafe(); err != nil { if err := cs.saveStoreUnsafe(); err != nil {