refactor: migrate all log statements to structured logger calls for improved observability

This commit is contained in:
2026-08-15 00:15:27 -07:00
parent 86a092ecd3
commit 150e3dfbd5
6 changed files with 43 additions and 31 deletions
+4 -5
View File
@@ -30,8 +30,7 @@ func newRootCmd() *cobra.Command {
logger.Log.Info("==========================================================") logger.Log.Info("==========================================================")
logger.Log.Info("🚀 Starting Hireme (GJCC) Job Application Command Center") logger.Log.Info("🚀 Starting Hireme (GJCC) Job Application Command Center")
logger.Log.Info("==========================================================") logger.Log.Info("==========================================================")
logger.Log.Infof("[Config] Port: %s | DB Path: %s | Target Config: %s | Active LLM: %s | Log Level: %s", logger.Log.Infow("Starting Hireme", "component", "Config", "port", cfg.Port, "db_path", cfg.DBPath, "target_config", cfg.TargetConfig, "llm", cfg.LLMProvider, "log_level", cfg.LogLevel)
cfg.Port, cfg.DBPath, cfg.TargetConfig, cfg.LLMProvider, cfg.LogLevel)
// Ensure DB directory exists // Ensure DB directory exists
dbDir := filepath.Dir(cfg.DBPath) dbDir := filepath.Dir(cfg.DBPath)
@@ -48,7 +47,7 @@ func newRootCmd() *cobra.Command {
// Load targets from YAML config if database is empty // Load targets from YAML config if database is empty
if err := database.LoadTargetsFromYAML(cfg.TargetConfig); err != nil { if err := database.LoadTargetsFromYAML(cfg.TargetConfig); err != nil {
logger.Log.Errorf("[Main] Target YAML loading status: %v", err) logger.Log.Errorw("Target YAML loading failed", "component", "Main", "error", err)
} }
// Initialize LLM Analyzer // Initialize LLM Analyzer
@@ -60,7 +59,7 @@ func newRootCmd() *cobra.Command {
// Load filter configuration // Load filter configuration
filterCfg, err := config.LoadFilterConfig(cfg.FilterConfig) filterCfg, err := config.LoadFilterConfig(cfg.FilterConfig)
if err != nil { if err != nil {
logger.Log.Fatalf("Failed to load filter config: %v", err) logger.Log.Fatalw("Failed to load filter config", "component", "Main", "error", err)
} }
// 4. Initialize Worker Pool // 4. Initialize Worker Pool
@@ -73,7 +72,7 @@ func newRootCmd() *cobra.Command {
server.RegisterRoutes(mux) server.RegisterRoutes(mux)
addr := fmt.Sprintf(":%s", cfg.Port) addr := fmt.Sprintf(":%s", cfg.Port)
logger.Log.Infof("✨ Hireme Command Center is live at http://localhost:%s", cfg.Port) logger.Log.Infow("Hireme Command Center is live", "component", "Main", "url", fmt.Sprintf("http://localhost:%s", cfg.Port))
return http.ListenAndServe(addr, mux) return http.ListenAndServe(addr, mux)
}, },
} }
+2 -2
View File
@@ -3,8 +3,8 @@ package db
import ( import (
"database/sql" "database/sql"
"fmt" "fmt"
"log"
"github.com/hireme/hireme/internal/logger"
_ "github.com/mattn/go-sqlite3" _ "github.com/mattn/go-sqlite3"
) )
@@ -31,7 +31,7 @@ func InitDB(dbPath string) (*DB, error) {
return nil, fmt.Errorf("failed to run sqlite migrations: %w", err) return nil, fmt.Errorf("failed to run sqlite migrations: %w", err)
} }
log.Printf("[DB] SQLite database initialized successfully at %s", dbPath) logger.Log.Infow("SQLite database initialized successfully", "component", "DB", "dbPath", dbPath)
return database, nil return database, nil
} }
+3 -2
View File
@@ -4,7 +4,8 @@ import (
"database/sql" "database/sql"
"encoding/json" "encoding/json"
"fmt" "fmt"
"log"
"github.com/hireme/hireme/internal/logger"
) )
// QueueStats holds task queue counters // QueueStats holds task queue counters
@@ -96,7 +97,7 @@ func (db *DB) FailTask(id int64, errStr string) error {
var retryCount int var retryCount int
err := db.QueryRow(`SELECT retry_count FROM tasks WHERE id = ?`, id).Scan(&retryCount) err := db.QueryRow(`SELECT retry_count FROM tasks WHERE id = ?`, id).Scan(&retryCount)
if err != nil { if err != nil {
log.Printf("[DB] FailTask: failed to get retry_count for task %d: %v", id, err) logger.Log.Errorw("FailTask: failed to get retry_count", "component", "DB", "task_id", id, "error", err)
return err return err
} }
+18 -6
View File
@@ -94,7 +94,7 @@ func (s *Server) handleIndex(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "text/html; charset=utf-8") w.Header().Set("Content-Type", "text/html; charset=utf-8")
if err := RenderPage(w, data); err != nil { if err := RenderPage(w, data); err != nil {
logger.Log.Errorf("[UI] RenderPage error: %v", err) logger.Log.Errorw("RenderPage error", "component", "UI", "error", err)
} }
} }
@@ -124,6 +124,8 @@ func (s *Server) handleCreateTarget(w http.ResponseWriter, r *http.Request) {
return return
} }
logger.Log.Infow("Triggered /targets (Create)", "component", "API", "name", name, "platform", platform)
_, err := s.db.CreateTarget(name, targetURL, platform) _, err := s.db.CreateTarget(name, targetURL, platform)
if err != nil { if err != nil {
http.Error(w, err.Error(), http.StatusInternalServerError) http.Error(w, err.Error(), http.StatusInternalServerError)
@@ -141,6 +143,8 @@ func (s *Server) handleToggleTarget(w http.ResponseWriter, r *http.Request) {
return return
} }
logger.Log.Infow("Triggered /targets/{id}/toggle", "component", "API", "target_id", id)
if err := s.db.ToggleTargetStatus(id); err != nil { if err := s.db.ToggleTargetStatus(id); err != nil {
http.Error(w, err.Error(), http.StatusInternalServerError) http.Error(w, err.Error(), http.StatusInternalServerError)
return return
@@ -186,6 +190,8 @@ func (s *Server) handleAnalyzeJob(w http.ResponseWriter, r *http.Request) {
return return
} }
logger.Log.Infow("Triggered /jobs/{id}/analyze", "component", "API", "job_id", id)
// Enqueue analyze task instead of synchronous processing // Enqueue analyze task instead of synchronous processing
payload := worker.AnalyzePayload{RawJobID: int64(id)} payload := worker.AnalyzePayload{RawJobID: int64(id)}
err = s.db.EnqueueTask("ANALYZE", payload) err = s.db.EnqueueTask("ANALYZE", payload)
@@ -206,6 +212,8 @@ func (s *Server) handleOptOut(w http.ResponseWriter, r *http.Request) {
return return
} }
logger.Log.Infow("Triggered /jobs/{id}/opt-out", "component", "API", "job_id", id)
_, err = s.db.CreateOrUpdateApplication(id, "OPTED_OUT", "") _, err = s.db.CreateOrUpdateApplication(id, "OPTED_OUT", "")
if err != nil { if err != nil {
http.Error(w, err.Error(), http.StatusInternalServerError) http.Error(w, err.Error(), http.StatusInternalServerError)
@@ -249,6 +257,8 @@ func (s *Server) handleCreateApplication(w http.ResponseWriter, r *http.Request)
return return
} }
logger.Log.Infow("Triggered /applications (Create)", "component", "API", "raw_job_id", rawJobID, "status", status)
_, err = s.db.CreateOrUpdateApplication(rawJobID, status, "") _, err = s.db.CreateOrUpdateApplication(rawJobID, status, "")
if err != nil { if err != nil {
http.Error(w, err.Error(), http.StatusInternalServerError) http.Error(w, err.Error(), http.StatusInternalServerError)
@@ -278,6 +288,8 @@ func (s *Server) handleUpdateAppStatus(w http.ResponseWriter, r *http.Request) {
return return
} }
logger.Log.Infow("Triggered /applications/{id}/status (Update)", "component", "API", "app_id", appID, "new_status", newStatus)
// Fetch rawJobID for appID // Fetch rawJobID for appID
apps, err := s.db.GetApplications() apps, err := s.db.GetApplications()
if err != nil { if err != nil {
@@ -310,7 +322,7 @@ func (s *Server) handleUpdateAppStatus(w http.ResponseWriter, r *http.Request) {
} }
func (s *Server) handleDiscoverTasks(w http.ResponseWriter, r *http.Request) { func (s *Server) handleDiscoverTasks(w http.ResponseWriter, r *http.Request) {
logger.Log.Info("[API] Triggered /api/tasks/discover") logger.Log.Infow("Triggered /api/tasks/discover", "component", "API")
targets, err := s.db.GetAllTargets() targets, err := s.db.GetAllTargets()
if err != nil { if err != nil {
http.Error(w, err.Error(), http.StatusInternalServerError) http.Error(w, err.Error(), http.StatusInternalServerError)
@@ -337,7 +349,7 @@ func (s *Server) handleDiscoverTasks(w http.ResponseWriter, r *http.Request) {
} }
func (s *Server) handleCleanTasks(w http.ResponseWriter, r *http.Request) { func (s *Server) handleCleanTasks(w http.ResponseWriter, r *http.Request) {
logger.Log.Info("[API] Triggered /api/tasks/clean") logger.Log.Infow("Triggered /api/tasks/clean", "component", "API")
err := s.db.ClearTaskQueue() err := s.db.ClearTaskQueue()
if err != nil { if err != nil {
http.Error(w, err.Error(), http.StatusInternalServerError) http.Error(w, err.Error(), http.StatusInternalServerError)
@@ -348,9 +360,9 @@ func (s *Server) handleCleanTasks(w http.ResponseWriter, r *http.Request) {
} }
func (s *Server) handleReprocessJobs(w http.ResponseWriter, r *http.Request) { func (s *Server) handleReprocessJobs(w http.ResponseWriter, r *http.Request) {
logger.Log.Info("[API] Triggered /api/tasks/reprocess") logger.Log.Infow("Triggered /api/tasks/reprocess", "component", "API")
if err := s.db.ReprocessAllJobs(); err != nil { if err := s.db.ReprocessAllJobs(); err != nil {
logger.Log.Errorf("[API] Failed to reprocess jobs: %v", err) logger.Log.Errorw("Failed to reprocess jobs", "component", "API", "error", err)
http.Error(w, err.Error(), http.StatusInternalServerError) http.Error(w, err.Error(), http.StatusInternalServerError)
return return
} }
@@ -359,7 +371,7 @@ func (s *Server) handleReprocessJobs(w http.ResponseWriter, r *http.Request) {
} }
func (s *Server) handleToggleTasks(w http.ResponseWriter, r *http.Request) { func (s *Server) handleToggleTasks(w http.ResponseWriter, r *http.Request) {
logger.Log.Info("[API] Triggered /api/tasks/toggle") logger.Log.Infow("Triggered /api/tasks/toggle", "component", "API")
isRunning := s.pool.Toggle() isRunning := s.pool.Toggle()
status := "paused" status := "paused"
if isRunning { if isRunning {
+8 -8
View File
@@ -68,7 +68,7 @@ func (p *WorkerPool) Start() {
p.wg.Add(1) p.wg.Add(1)
go p.workerLoop(i) go p.workerLoop(i)
} }
logger.Log.Infof("[WorkerPool] Started %d workers", p.workerCount) logger.Log.Infow("Started workers", "component", "WorkerPool", "count", p.workerCount)
} }
func (p *WorkerPool) Stop() { func (p *WorkerPool) Stop() {
@@ -78,22 +78,22 @@ func (p *WorkerPool) Stop() {
p.cancel() p.cancel()
p.isRunning.Store(false) p.isRunning.Store(false)
p.wg.Wait() p.wg.Wait()
logger.Log.Infof("[WorkerPool] All workers stopped") logger.Log.Infow("All workers stopped", "component", "WorkerPool")
} }
func (p *WorkerPool) workerLoop(workerID int) { func (p *WorkerPool) workerLoop(workerID int) {
defer p.wg.Done() defer p.wg.Done()
logger.Log.Debugf("[Worker %d] Starting loop", workerID) logger.Log.Debugw("Starting loop", "component", "Worker", "worker_id", workerID)
for { for {
select { select {
case <-p.ctx.Done(): case <-p.ctx.Done():
logger.Log.Debugf("[Worker %d] Context cancelled, exiting", workerID) logger.Log.Debugw("Context cancelled, exiting", "component", "Worker", "worker_id", workerID)
return return
default: default:
task, err := p.db.ClaimNextTask() task, err := p.db.ClaimNextTask()
if err != nil { if err != nil {
logger.Log.Errorf("[Worker %d] Error claiming task: %v", workerID, err) logger.Log.Errorw("Error claiming task", "component", "Worker", "worker_id", workerID, "error", err)
time.Sleep(1 * time.Second) time.Sleep(1 * time.Second)
continue continue
} }
@@ -104,7 +104,7 @@ func (p *WorkerPool) workerLoop(workerID int) {
continue continue
} }
logger.Log.Debugf("[Worker %d] Picked up task %d (%s)", workerID, task.ID, task.TaskType) logger.Log.Debugw("Picked up task", "component", "Worker", "worker_id", workerID, "task_id", task.ID, "task_type", task.TaskType)
// Process task based on type // Process task based on type
var processErr error var processErr error
@@ -122,10 +122,10 @@ func (p *WorkerPool) workerLoop(workerID int) {
} }
if processErr != nil { if processErr != nil {
logger.Log.Errorf("[Worker %d] Task %d FAILED: %v", workerID, task.ID, processErr) logger.Log.Errorw("Task FAILED", "component", "Worker", "worker_id", workerID, "task_id", task.ID, "error", processErr)
_ = p.db.FailTask(task.ID, processErr.Error()) _ = p.db.FailTask(task.ID, processErr.Error())
} else { } else {
logger.Log.Debugf("[Worker %d] Task %d COMPLETED", workerID, task.ID) logger.Log.Debugw("Task COMPLETED", "component", "Worker", "worker_id", workerID, "task_id", task.ID)
_ = p.db.CompleteTask(task.ID) _ = p.db.CompleteTask(task.ID)
} }
} }
+8 -8
View File
@@ -7,7 +7,6 @@ import (
"encoding/json" "encoding/json"
"fmt" "fmt"
"io" "io"
"log"
"net/http" "net/http"
"regexp" "regexp"
"strings" "strings"
@@ -15,6 +14,7 @@ import (
md "github.com/JohannesKaufmann/html-to-markdown/v2" md "github.com/JohannesKaufmann/html-to-markdown/v2"
"github.com/hireme/hireme/internal/crawler" "github.com/hireme/hireme/internal/crawler"
"github.com/hireme/hireme/internal/logger"
"golang.org/x/net/html" "golang.org/x/net/html"
) )
@@ -183,7 +183,7 @@ func extractFromAFData(htmlContent string) (title, company, location string) {
marker := `AF_initDataCallback({key: 'ds:0'` marker := `AF_initDataCallback({key: 'ds:0'`
idx := strings.Index(htmlContent, marker) idx := strings.Index(htmlContent, marker)
if idx == -1 { if idx == -1 {
log.Printf("[GoogleCrawler] AF_initDataCallback ds:0 not found") logger.Log.Debugw("AF_initDataCallback ds:0 not found", "component", "GoogleCrawler")
return "", "", "" return "", "", ""
} }
@@ -191,7 +191,7 @@ func extractFromAFData(htmlContent string) (title, company, location string) {
dataMarker := "data:" dataMarker := "data:"
dataIdx := strings.Index(htmlContent[idx:], dataMarker) dataIdx := strings.Index(htmlContent[idx:], dataMarker)
if dataIdx == -1 { if dataIdx == -1 {
log.Printf("[GoogleCrawler] 'data:' not found after ds:0 marker") logger.Log.Debugw("'data:' not found after ds:0 marker", "component", "GoogleCrawler")
return "", "", "" return "", "", ""
} }
dataStart := idx + dataIdx + len(dataMarker) dataStart := idx + dataIdx + len(dataMarker)
@@ -199,14 +199,14 @@ func extractFromAFData(htmlContent string) (title, company, location string) {
// Use bracket counting to find the matching ] for the outer [ // Use bracket counting to find the matching ] for the outer [
jsonStr := extractBalancedBracket(htmlContent, dataStart) jsonStr := extractBalancedBracket(htmlContent, dataStart)
if jsonStr == "" { if jsonStr == "" {
log.Printf("[GoogleCrawler] Failed to extract balanced bracket for ds:0 data") logger.Log.Debugw("Failed to extract balanced bracket for ds:0 data", "component", "GoogleCrawler")
return "", "", "" return "", "", ""
} }
// Parse the outer array: data = [[...job record...]] // Parse the outer array: data = [[...job record...]]
var outerArray []json.RawMessage var outerArray []json.RawMessage
if err := json.Unmarshal([]byte(jsonStr), &outerArray); err != nil { if err := json.Unmarshal([]byte(jsonStr), &outerArray); err != nil {
log.Printf("[GoogleCrawler] JSON parse error for ds:0 outer: %v", err) logger.Log.Debugw("JSON parse error for ds:0 outer", "component", "GoogleCrawler", "error", err)
return "", "", "" return "", "", ""
} }
if len(outerArray) == 0 { if len(outerArray) == 0 {
@@ -216,7 +216,7 @@ func extractFromAFData(htmlContent string) (title, company, location string) {
// Parse inner job record array // Parse inner job record array
var record []json.RawMessage var record []json.RawMessage
if err := json.Unmarshal(outerArray[0], &record); err != nil { if err := json.Unmarshal(outerArray[0], &record); err != nil {
log.Printf("[GoogleCrawler] JSON parse error for job record: %v", err) logger.Log.Debugw("JSON parse error for job record", "component", "GoogleCrawler", "error", err)
return "", "", "" return "", "", ""
} }
@@ -247,7 +247,7 @@ func extractFromAFData(htmlContent string) (title, company, location string) {
} }
} }
log.Printf("[GoogleCrawler] AF_initDataCallback parsed: title=%q company=%q location=%q", title, company, location) logger.Log.Debugw("AF_initDataCallback parsed job", "component", "GoogleCrawler", "title", title, "company", company, "location", location)
return title, company, location return title, company, location
} }
@@ -309,7 +309,7 @@ func (g *GoogleCrawler) fetchWithRetry(ctx context.Context, urlStr string) (stri
for attempt := 0; attempt < 3; attempt++ { for attempt := 0; attempt < 3; attempt++ {
if attempt > 0 { if attempt > 0 {
delay := time.Duration(attempt) * 2 * time.Second delay := time.Duration(attempt) * 2 * time.Second
log.Printf("[GoogleCrawler] Retry #%d for %s after %v", attempt, urlStr, delay) logger.Log.Warnw("Retrying request", "component", "GoogleCrawler", "attempt", attempt, "url", urlStr, "delay", delay)
time.Sleep(delay) time.Sleep(delay)
} }