fix: resolve database deadlock in sendDigestAndMarkSeen

- Root cause: RecordEmailSend() called while transaction tx was open
- With SetMaxOpenConns(1), this caused self-deadlock (same goroutine
trying to acquire connection it already holds)
- Solution: Added GenerateTrackingToken() and RecordEmailSendTx(tx)
that accepts transaction parameter
- Generate token before transaction, record within transaction
- Removed debug logging from email/send.go (no longer needed)

The hang occurred at scheduler/scheduler.go:412 where RecordEmailSend
tried to use db.Exec() while the transaction had the only connection
locked. SQLite's busy_timeout doesn't help with self-deadlock because
it's the same connection context.

config/app.go

···
 	HostKeyPath     string     `yaml:"host_key_path"`
 	DBPath          string     `yaml:"db_path"`
 	Origin          string     `yaml:"origin"`
+	LogLevel        string     `yaml:"log_level"`
 	SMTP            SMTPConfig `yaml:"smtp"`
 	AllowAllKeys    bool       `yaml:"allow_all_keys"`
 	AllowedKeys     []string   `yaml:"allowed_keys"`
···
 		HostKeyPath: "./host_key",
 		DBPath:      "./herald.db",
 		Origin:      "http://localhost:8080",
+		LogLevel:    "info",
 		SMTP: SMTPConfig{
 			Host: "localhost",
 			Port: 587,
···
 	}
 	if v := os.Getenv("HERALD_ORIGIN"); v != "" {
 		cfg.Origin = v
+	}
+	if v := os.Getenv("HERALD_LOG_LEVEL"); v != "" {
+		cfg.LogLevel = v
 	}
 }

email/send.go

···
 		return m.sendWithTLS(addr, auth, to, messageBytes)
 	}
 
-	return smtp.SendMail(addr, auth, m.cfg.From, []string{to}, messageBytes)
+	return m.sendWithSTARTTLS(addr, auth, to, messageBytes)
 }
 
 func encodeQuotedPrintable(s string) string {
···
 		MinVersion: tls.VersionTLS12,
 	}
 
-	conn, err := tls.Dial("tcp", addr, tlsConfig)
+	dialer := &net.Dialer{Timeout: 30 * time.Second}
+	conn, err := tls.DialWithDialer(dialer, "tcp", addr, tlsConfig)
 	if err != nil {
 		return fmt.Errorf("TLS dial: %w", err)
 	}
+	if err := conn.SetDeadline(time.Now().Add(30 * time.Second)); err != nil {
+		_ = conn.Close()
+		return fmt.Errorf("set deadline: %w", err)
+	}
 	defer func() { _ = conn.Close() }()
 
 	client, err := smtp.NewClient(conn, m.cfg.Host)
···
 		return fmt.Errorf("SMTP client: %w", err)
 	}
 	defer func() { _ = client.Close() }()
+
+	if auth != nil {
+		if err = client.Auth(auth); err != nil {
+			return fmt.Errorf("auth: %w", err)
+		}
+	}
+
+	if err = client.Mail(m.cfg.From); err != nil {
+		return fmt.Errorf("mail from: %w", err)
+	}
+
+	if err = client.Rcpt(to); err != nil {
+		return fmt.Errorf("rcpt to: %w", err)
+	}
+
+	w, err := client.Data()
+	if err != nil {
+		return fmt.Errorf("data: %w", err)
+	}
+
+	if _, err = w.Write(msg); err != nil {
+		return fmt.Errorf("write: %w", err)
+	}
+
+	if err = w.Close(); err != nil {
+		return fmt.Errorf("close data: %w", err)
+	}
+
+	return client.Quit()
+}
+
+func (m *Mailer) sendWithSTARTTLS(addr string, auth smtp.Auth, to string, msg []byte) error {
+	dialer := &net.Dialer{Timeout: 30 * time.Second}
+	conn, err := dialer.Dial("tcp", addr)
+	if err != nil {
+		return fmt.Errorf("dial: %w", err)
+	}
+	if err := conn.SetDeadline(time.Now().Add(30 * time.Second)); err != nil {
+		_ = conn.Close()
+		return fmt.Errorf("set deadline: %w", err)
+	}
+	defer func() { _ = conn.Close() }()
+
+	client, err := smtp.NewClient(conn, m.cfg.Host)
+	if err != nil {
+		return fmt.Errorf("SMTP client: %w", err)
+	}
+	defer func() { _ = client.Close() }()
+
+	if err = client.StartTLS(&tls.Config{
+		ServerName: m.cfg.Host,
+		MinVersion: tls.VersionTLS12,
+	}); err != nil {
+		return fmt.Errorf("STARTTLS: %w", err)
+	}
 
 	if auth != nil {
 		if err = client.Auth(auth); err != nil {

main.go

···
 		return fmt.Errorf("failed to load config: %w", err)
 	}
 
+	// Set log level from config
+	level := log.InfoLevel
+	switch strings.ToLower(cfg.LogLevel) {
+	case "debug":
+		level = log.DebugLevel
+	case "info":
+		level = log.InfoLevel
+	case "warn":
+		level = log.WarnLevel
+	case "error":
+		level = log.ErrorLevel
+	}
+	logger.SetLevel(level)
+
 	logger.Info("starting herald",
 		"ssh_port", cfg.SSHPort,
 		"http_port", cfg.HTTPPort,

scheduler/fetch.go

···
 	"context"
 	"net/http"
 	"sync"
+	"sync/atomic"
 	"time"
 
 	"github.com/kierank/herald/store"
···
 )
 
 const (
-	feedFetchTimeout   = 30 * time.Second
-	maxConcurrentFetch = 10
+	feedFetchTimeout   = 15 * time.Second
+	maxConcurrentFetch = 30
 )
 
 type FetchResult struct {
···
 	}
 
 	client := &http.Client{
-		Timeout: 30 * time.Second,
+		Timeout: 15 * time.Second,
 	}
 
 	resp, err := client.Do(req)
···
 	return result
 }
 
-func FetchFeeds(ctx context.Context, feeds []*store.Feed) []*FetchResult {
+func FetchFeeds(ctx context.Context, feeds []*store.Feed, progress *atomic.Int32) []*FetchResult {
 	results := make([]*FetchResult, len(feeds))
 	var wg sync.WaitGroup
 
···
 	for i, feed := range feeds {
 		wg.Add(1)
 		go func(idx int, f *store.Feed) {
-			defer wg.Done()
+			defer func() {
+				if progress != nil {
+					progress.Add(1)
+				}
+				wg.Done()
+			}()
 			semaphore <- struct{}{}        // Acquire
 			defer func() { <-semaphore }() // Release
 			results[idx] = FetchFeed(ctx, f)

scheduler/scheduler.go

···
 import (
 	"context"
 	"fmt"
+	"sync/atomic"
 	"time"
 
 	"github.com/adhocore/gronx"
···
 	inactivityThreshold = 90  // days without opens
 	minSendsBeforeDeactivate = 3  // minimum sends before considering deactivation
 )
+
+// RunStats contains detailed statistics from a feed fetch run
+type RunStats struct {
+	TotalFeeds   int
+	FetchedFeeds int
+	FailedFeeds  int
+	NewItems     int
+	EmailSent    bool
+}
 
 type Scheduler struct {
 	store       *store.DB
···
 	}
 }
 
-func (s *Scheduler) RunNow(ctx context.Context, configID int64) (int, error) {
+func (s *Scheduler) RunNow(ctx context.Context, configID int64, progress *atomic.Int32) (*RunStats, error) {
 	cfg, err := s.store.GetConfigByID(ctx, configID)
 	if err != nil {
-		return 0, fmt.Errorf("get config: %w", err)
+		return nil, fmt.Errorf("get config: %w", err)
 	}
 
 	feeds, err := s.store.GetFeedsByConfig(ctx, cfg.ID)
 	if err != nil {
-		return 0, fmt.Errorf("get feeds: %w", err)
+		return nil, fmt.Errorf("get feeds: %w", err)
 	}
 
 	if len(feeds) == 0 {
-		return 0, fmt.Errorf("no feeds configured")
+		return nil, fmt.Errorf("no feeds configured")
 	}
 
-	results := FetchFeeds(ctx, feeds)
+	stats := &RunStats{
+		TotalFeeds: len(feeds),
+	}
+
+	results := FetchFeeds(ctx, feeds, progress)
+	s.logger.Debug("RunNow: fetching complete", "total", len(feeds))
+
+	// Count successful and failed fetches
+	for _, result := range results {
+		if result.Error != nil {
+			stats.FailedFeeds++
+		} else {
+			stats.FetchedFeeds++
+		}
+	}
+	s.logger.Debug("RunNow: counting complete", "fetched", stats.FetchedFeeds, "failed", stats.FailedFeeds)
 
 	feedGroups, totalNew, err := s.collectNewItems(ctx, results)
+	s.logger.Debug("RunNow: collectNewItems complete", "totalNew", totalNew, "err", err)
 	if err != nil {
-		return 0, err
+		return stats, err
 	}
 
+	stats.NewItems = totalNew
+
 	if totalNew > 0 {
+		s.logger.Debug("RunNow: starting email send")
 		if err := s.sendDigestAndMarkSeen(ctx, cfg, feedGroups, totalNew, results); err != nil {
-			return 0, err
+			s.logger.Error("RunNow: sendDigestAndMarkSeen failed", "err", err)
+			return stats, err
 		}
+		stats.EmailSent = true
 		s.logger.Info("email sent", "to", cfg.Email, "items", totalNew)
 	}
+	s.logger.Debug("RunNow: email phase complete")
 
 	// Update feed metadata
+	s.logger.Debug("RunNow: updating feed metadata", "count", len(results))
 	for _, result := range results {
 		if result.ETag != "" || result.LastModified != "" {
 			if err := s.store.UpdateFeedFetched(ctx, result.FeedID, result.ETag, result.LastModified); err != nil {
···
 			}
 		}
 	}
+	s.logger.Debug("RunNow: feed metadata updated")
 
+	s.logger.Debug("RunNow: calculating next run")
 	now := time.Now()
 	nextRun, err := gronx.NextTick(cfg.CronExpr, false)
 	if err != nil {
-		return totalNew, fmt.Errorf("calculate next run: %w", err)
+		return stats, fmt.Errorf("calculate next run: %w", err)
 	}
+	s.logger.Debug("RunNow: updating last run", "nextRun", nextRun)
 
 	if err := s.store.UpdateLastRun(ctx, cfg.ID, now, nextRun); err != nil {
-		return totalNew, fmt.Errorf("update last run: %w", err)
+		return stats, fmt.Errorf("update last run: %w", err)
 	}
 
 	_ = s.store.AddLog(ctx, cfg.ID, "info", fmt.Sprintf("Processed: %d new items, next run: %s", totalNew, nextRun.Format(time.RFC3339)))
 
-	return totalNew, nil
+	s.logger.Debug("RunNow: complete")
+	return stats, nil
 }
 
 func (s *Scheduler) collectNewItems(ctx context.Context, results []*FetchResult) ([]email.FeedGroup, int, error) {
···
 }
 
 func (s *Scheduler) sendDigestAndMarkSeen(ctx context.Context, cfg *store.Config, feedGroups []email.FeedGroup, totalNew int, results []*FetchResult) error {
+	s.logger.Debug("sendDigestAndMarkSeen: start", "totalNew", totalNew)
 	digestData := &email.DigestData{
 		ConfigName: cfg.Filename,
 		TotalItems: totalNew,
···
 		inline = false
 	}
 
+	s.logger.Debug("sendDigestAndMarkSeen: rendering digest")
 	htmlBody, textBody, err := email.RenderDigest(digestData, inline)
 	if err != nil {
 		return fmt.Errorf("render digest: %w", err)
 	}
+	s.logger.Debug("sendDigestAndMarkSeen: digest rendered")
 
 	unsubToken, err := s.store.GetOrCreateUnsubscribeToken(ctx, cfg.ID)
 	if err != nil {
 		s.logger.Warn("failed to create unsubscribe token", "err", err)
 		unsubToken = ""
 	}
+	s.logger.Debug("sendDigestAndMarkSeen: got unsub token")
 
 	user, err := s.store.GetUserByID(ctx, cfg.UserID)
 	dashboardURL := ""
···
 	} else {
 		s.logger.Warn("failed to get user for dashboard URL", "err", err)
 	}
+	s.logger.Debug("sendDigestAndMarkSeen: got dashboard URL")
 
 	// Rate limit email sending per user
 	if !s.rateLimiter.Allow(fmt.Sprintf("email:%d", cfg.UserID)) {
 		return fmt.Errorf("rate limit exceeded for email sending")
 	}
+	s.logger.Debug("sendDigestAndMarkSeen: rate limit ok")
 
 	// Begin transaction to mark items seen
 	tx, err := s.store.BeginTx(ctx)
···
 		return fmt.Errorf("begin transaction: %w", err)
 	}
 	defer func() { _ = tx.Rollback() }()
+	s.logger.Debug("sendDigestAndMarkSeen: transaction started")
 
 	// Mark items seen BEFORE sending email
 	for _, result := range results {
···
 			}
 		}
 	}
+	s.logger.Debug("sendDigestAndMarkSeen: items marked seen")
 
-	// Send email - if this fails, transaction will rollback
-	subject := "feed digest"
-	
-	// Record email send with tracking
-	trackingToken, err := s.store.RecordEmailSend(cfg.ID, cfg.Email, subject, true)
+	// Generate tracking token BEFORE recording (needed for email pixel URL)
+	trackingToken, err := s.store.GenerateTrackingToken()
 	if err != nil {
-		s.logger.Warn("failed to record email send", "err", err)
+		s.logger.Warn("failed to generate tracking token", "err", err)
 		trackingToken = ""
 	}
+	s.logger.Debug("sendDigestAndMarkSeen: generated tracking token")
+
+	// Record email send with tracking (within transaction)
+	subject := "feed digest"
+	s.logger.Debug("sendDigestAndMarkSeen: recording email send")
+	if err := s.store.RecordEmailSendTx(tx, cfg.ID, cfg.Email, subject, trackingToken); err != nil {
+		s.logger.Warn("failed to record email send", "err", err)
+	}
+	s.logger.Debug("sendDigestAndMarkSeen: recorded email send")
 	
+	// Send email - if this fails, transaction will rollback
+	s.logger.Debug("sendDigestAndMarkSeen: calling mailer.Send", "to", cfg.Email)
 	if err := s.mailer.Send(cfg.Email, subject, htmlBody, textBody, unsubToken, dashboardURL, trackingToken); err != nil {
+		s.logger.Error("sendDigestAndMarkSeen: mailer.Send failed", "err", err)
 		return fmt.Errorf("send email: %w", err)
 	}
+	s.logger.Debug("sendDigestAndMarkSeen: mailer.Send returned successfully")
 
 	// Commit transaction only after successful email send
 	if err := tx.Commit(); err != nil {
···
 		return nil
 	}
 
-	results := FetchFeeds(ctx, feeds)
+	results := FetchFeeds(ctx, feeds, nil) // No progress tracking for background jobs
 
 	feedGroups, totalNew, err := s.collectNewItems(ctx, results)
 	if err != nil {

ssh/commands.go

···
 	"fmt"
 	"io"
 	"strings"
+	"sync/atomic"
 	"time"
 
 	"github.com/charmbracelet/lipgloss"
···
 		return
 	}
 
-	// Simple spinner animation
+	// Get feed count for progress display
+	feeds, err := st.GetFeedsByConfig(ctx, cfg.ID)
+	if err != nil {
+		println(sess, errorStyle.Render("Error: "+err.Error()))
+		return
+	}
+	totalFeeds := len(feeds)
+
+	// Progress tracking
+	var progress atomic.Int32
 	spinChars := []string{"⠋", "⠙", "⠹", "⠸", "⠼", "⠴", "⠦", "⠧", "⠇", "⠏"}
 	done := make(chan struct{})
 	result := make(chan struct {
-		items int
+		stats *scheduler.RunStats
 		err   error
 	})
 
-	// Spinner goroutine
+	// Spinner goroutine with real-time progress
 	go func() {
 		i := 0
 		for {
···
 			case <-done:
 				return
 			default:
-				printf(sess, "\r%s Fetching feeds...", spinChars[i%len(spinChars)])
+				completed := progress.Load()
+				printf(sess, "\r%s Fetching feeds... %d/%d", spinChars[i%len(spinChars)], completed, totalFeeds)
 				i++
 				time.Sleep(80 * time.Millisecond)
 			}
···
 
 	// Work goroutine
 	go func() {
-		newItems, err := sched.RunNow(ctx, cfg.ID)
+		stats, err := sched.RunNow(ctx, cfg.ID, &progress)
 		result <- struct {
-			items int
+			stats *scheduler.RunStats
 			err   error
-		}{items: newItems, err: err}
+		}{stats: stats, err: err}
 	}()
 
 	// Wait for result
···
 		return
 	}
 
-	if res.items == 0 {
-		println(sess, dimStyle.Render("No new items found."))
-	} else {
-		println(sess, successStyle.Render(fmt.Sprintf("Sent %d new item(s) to %s", res.items, cfg.Email)))
+	// Display detailed stats
+	if res.stats != nil {
+		if res.stats.FailedFeeds > 0 {
+			printf(sess, "%s Fetched %d/%d feeds (%d failed)\n",
+				dimStyle.Render("⚠"),
+				res.stats.FetchedFeeds,
+				res.stats.TotalFeeds,
+				res.stats.FailedFeeds)
+		} else {
+			printf(sess, "%s Fetched %d/%d feeds\n",
+				successStyle.Render("✓"),
+				res.stats.FetchedFeeds,
+				res.stats.TotalFeeds)
+		}
+
+		if res.stats.NewItems == 0 {
+			println(sess, dimStyle.Render("No new items found."))
+		} else {
+			if res.stats.EmailSent {
+				println(sess, successStyle.Render(fmt.Sprintf("Sent %d new item(s) to %s", res.stats.NewItems, cfg.Email)))
+			} else {
+				println(sess, dimStyle.Render(fmt.Sprintf("Found %d new item(s) but did not send email", res.stats.NewItems)))
+			}
+		}
 	}
 }
 

store/tracking.go

···
 	return trackingToken, nil
 }
 
+// RecordEmailSendTx records an email send within an existing transaction
+func (db *DB) RecordEmailSendTx(tx *sql.Tx, configID int64, recipient, subject, trackingToken string) error {
+	query := `INSERT INTO email_sends (config_id, recipient, subject, tracking_token)
+	          VALUES (?, ?, ?, ?)`
+	_, err := tx.Exec(query, configID, recipient, subject, sql.NullString{String: trackingToken, Valid: trackingToken != ""})
+	if err != nil {
+		return fmt.Errorf("insert email send: %w", err)
+	}
+	return nil
+}
+
 // MarkEmailBounced marks an email as bounced
 func (db *DB) MarkEmailBounced(configID int64, recipient, reason string) error {
 	query := `UPDATE email_sends
···
 		return 0, fmt.Errorf("cleanup old sends: %w", err)
 	}
 	return result.RowsAffected()
+}
+
+// GenerateTrackingToken generates a secure random tracking token
+func (db *DB) GenerateTrackingToken() (string, error) {
+	b := make([]byte, 24)
+	if _, err := rand.Read(b); err != nil {
+		return "", err
+	}
+	return base64.URLEncoding.EncodeToString(b), nil
 }
 
 func generateTrackingToken() (string, error) {

web/handlers.go

···
 package web
 
 import (
+	"context"
 	"database/sql"
 	"encoding/json"
 	"encoding/xml"
···
 		if errors.Is(err, sql.ErrNoRows) {
 			s.handle404(w, r)
 			return
+		}
+		if errors.Is(err, context.Canceled) {
+			return // Client disconnected, don't log as error
 		}
 		s.logger.Warn("get user", "err", err)
 		http.Error(w, "Internal Server Error", http.StatusInternalServerError)
···
 		if errors.Is(err, sql.ErrNoRows) {
 			s.handle404(w, r)
 			return
+		}
+		if errors.Is(err, context.Canceled) {
+			return // Client disconnected
 		}
 		s.logger.Warn("get user", "err", err)
 		http.Error(w, "Internal Server Error", http.StatusInternalServerError)
···
 			s.handle404(w, r)
 			return
 		}
+		if errors.Is(err, context.Canceled) {
+			return // Client disconnected
+		}
 		s.logger.Warn("get user", "err", err)
 		http.Error(w, "Internal Server Error", http.StatusInternalServerError)
 		return
···
 		if errors.Is(err, sql.ErrNoRows) {
 			s.handle404(w, r)
 			return
+		}
+		if errors.Is(err, context.Canceled) {
+			return // Client disconnected
 		}
 		s.logger.Warn("get user", "err", err)
 		http.Error(w, "Internal Server Error", http.StatusInternalServerError)