Enhance logging and error handling in configuration loading, content fetching, and AI reply generation

config/config.go

@@ -2,8 +2,11 @@ package config
 
 import (
 	"os"
+	"paraclub-ai-mailer/internal/logger"
+	"strings"
 	"time"
 
+	"github.com/sirupsen/logrus"
 	"gopkg.in/yaml.v3"
 )
 
@@ -46,15 +49,49 @@ type LoggingConfig struct {
 }
 
 func Load(path string) (*Config, error) {
+	logger.WithField("path", path).Debug("Loading configuration file")
+
 	data, err := os.ReadFile(path)
 	if err != nil {
+		logger.WithError(err).Error("Failed to read configuration file")
 		return nil, err
 	}
+	logger.WithField("bytes", len(data)).Debug("Read configuration file")
 
 	var config Config
 	if err := yaml.Unmarshal(data, &config); err != nil {
+		logger.WithError(err).Error("Failed to parse YAML configuration")
 		return nil, err
 	}
 
+	// Resolve environment variables in configuration
+	if strings.HasPrefix(config.IMAP.Password, "${") && strings.HasSuffix(config.IMAP.Password, "}") {
+		envVar := strings.TrimSuffix(strings.TrimPrefix(config.IMAP.Password, "${"), "}")
+		config.IMAP.Password = os.Getenv(envVar)
+		logger.WithField("envVar", envVar).Debug("Resolved IMAP password from environment")
+	}
+
+	if strings.HasPrefix(config.AI.OpenRouterAPIKey, "${") && strings.HasSuffix(config.AI.OpenRouterAPIKey, "}") {
+		envVar := strings.TrimSuffix(strings.TrimPrefix(config.AI.OpenRouterAPIKey, "${"), "}")
+		config.AI.OpenRouterAPIKey = os.Getenv(envVar)
+		logger.WithField("envVar", envVar).Debug("Resolved OpenRouter API key from environment")
+	}
+
+	logger.WithFields(logrus.Fields{
+		"imapServer":      config.IMAP.Server,
+		"imapPort":        config.IMAP.Port,
+		"imapUsername":    config.IMAP.Username,
+		"imapMailboxIn":   config.IMAP.MailboxIn,
+		"imapDraftBox":    config.IMAP.DraftBox,
+		"imapUseTLS":      config.IMAP.UseTLS,
+		"aiModel":         config.AI.Model,
+		"aiTemperature":   config.AI.Temperature,
+		"aiMaxTokens":     config.AI.MaxTokens,
+		"contextUrlCount": len(config.Context.URLs),
+		"pollingInterval": config.Polling.Interval,
+		"loggingLevel":    config.Logging.Level,
+		"loggingFilePath": config.Logging.FilePath,
+	}).Debug("Configuration loaded successfully")
+
 	return &config, nil
 }

internal/ai/ai.go

@@ -6,6 +6,9 @@ import (
 	"fmt"
 	"net/http"
 	"paraclub-ai-mailer/config"
+	"paraclub-ai-mailer/internal/logger"
+
+	"github.com/sirupsen/logrus"
 )
 
 type AI struct {
@@ -41,10 +44,19 @@ func New(cfg config.AIConfig) *AI {
 }
 
 func (a *AI) GenerateReply(emailContent string, contextContent map[string]string) (string, error) {
+	logger.WithFields(logrus.Fields{
+		"emailContentLength": len(emailContent),
+		"contextUrls":       len(contextContent),
+	}).Debug("Starting AI reply generation")
+
 	// Prepare context from all URLs
 	var context string
 	for url, content := range contextContent {
 		context += fmt.Sprintf("\nContext from %s:\n%s\n", url, content)
+		logger.WithFields(logrus.Fields{
+			"url":           url,
+			"contentLength": len(content),
+		}).Debug("Added context from URL")
 	}
 
 	// Prepare the system message and user message
@@ -64,6 +76,8 @@ func (a *AI) GenerateReply(emailContent string, contextContent map[string]string
 	var lastErr error
 
 	for attempt := 0; attempt < maxRetries; attempt++ {
+		logger.WithField("attempt", attempt+1).Debug("Making API request attempt")
+
 		reqBody := OpenRouterRequest{
 			Model:       a.config.Model,
 			Messages:    messages,
@@ -71,13 +85,21 @@ func (a *AI) GenerateReply(emailContent string, contextContent map[string]string
 			MaxTokens:   a.config.MaxTokens,
 		}
 
+		logger.WithFields(logrus.Fields{
+			"model":       reqBody.Model,
+			"temperature": reqBody.Temperature,
+			"maxTokens":   reqBody.MaxTokens,
+		}).Debug("Prepared API request")
+
 		jsonData, err := json.Marshal(reqBody)
 		if err != nil {
+			logger.WithError(err).Error("Failed to marshal request body")
 			return "", err
 		}
 
 		req, err := http.NewRequest("POST", "https://openrouter.ai/api/v1/chat/completions", bytes.NewBuffer(jsonData))
 		if err != nil {
+			logger.WithError(err).Error("Failed to create HTTP request")
 			return "", err
 		}
 
@@ -86,29 +108,51 @@ func (a *AI) GenerateReply(emailContent string, contextContent map[string]string
 
 		resp, err := a.client.Do(req)
 		if err != nil {
+			logger.WithFields(logrus.Fields{
+				"error":   err,
+				"attempt": attempt + 1,
+			}).Debug("API request failed, will retry")
 			lastErr = err
 			continue
 		}
 		defer resp.Body.Close()
 
 		if resp.StatusCode != http.StatusOK {
+			logger.WithFields(logrus.Fields{
+				"statusCode": resp.StatusCode,
+				"attempt":    attempt + 1,
+			}).Debug("API returned non-200 status code")
 			lastErr = fmt.Errorf("OpenRouter API returned status code: %d", resp.StatusCode)
 			continue
 		}
 
 		var result OpenRouterResponse
 		if err := json.NewDecoder(resp.Body).Decode(&result); err != nil {
+			logger.WithFields(logrus.Fields{
+				"error":   err,
+				"attempt": attempt + 1,
+			}).Debug("Failed to decode API response")
 			lastErr = err
 			continue
 		}
 
 		if len(result.Choices) == 0 || result.Choices[0].Message.Content == "" {
+			logger.WithField("attempt", attempt+1).Debug("Received empty response from API")
 			lastErr = fmt.Errorf("empty response received")
 			continue
 		}
 
+		responseLength := len(result.Choices[0].Message.Content)
+		logger.WithFields(logrus.Fields{
+			"attempt":        attempt + 1,
+			"responseLength": responseLength,
+		}).Debug("Successfully generated AI reply")
 		return result.Choices[0].Message.Content, nil
 	}
 
+	logger.WithFields(logrus.Fields{
+		"maxRetries": maxRetries,
+		"lastError":  lastErr,
+	}).Error("Failed to generate AI reply after all attempts")
 	return "", fmt.Errorf("failed after %d attempts, last error: %v", maxRetries, lastErr)
 }

internal/fetcher/fetcher.go

@@ -1,11 +1,14 @@
 package fetcher
 
 import (
+	"fmt"
 	"io"
 	"net/http"
+	"paraclub-ai-mailer/internal/logger"
 	"strings"
 	"time"
 
+	"github.com/sirupsen/logrus"
 	"golang.org/x/net/html"
 )
 
@@ -22,12 +25,17 @@ func New() *Fetcher {
 }
 
 func (f *Fetcher) extractText(htmlContent string) string {
+	logger.WithField("contentLength", len(htmlContent)).Debug("Starting HTML text extraction")
+
 	doc, err := html.Parse(strings.NewReader(htmlContent))
 	if err != nil {
-		return htmlContent // fallback to raw content if parsing fails
+		logger.WithError(err).Debug("Failed to parse HTML, falling back to raw content")
+		return htmlContent
 	}
 
 	var result strings.Builder
+	var textNodeCount int
+
 	var extractTextNode func(*html.Node)
 	extractTextNode = func(n *html.Node) {
 		if n.Type == html.TextNode {
@@ -35,6 +43,7 @@ func (f *Fetcher) extractText(htmlContent string) string {
 			if text != "" {
 				result.WriteString(text)
 				result.WriteString(" ")
+				textNodeCount++
 			}
 		}
 		for c := n.FirstChild; c != nil; c = c.NextSibling {
@@ -43,32 +52,84 @@ func (f *Fetcher) extractText(htmlContent string) string {
 	}
 
 	extractTextNode(doc)
-	return strings.TrimSpace(result.String())
+	extracted := strings.TrimSpace(result.String())
+
+	logger.WithFields(logrus.Fields{
+		"textNodeCount":   textNodeCount,
+		"extractedLength": len(extracted),
+	}).Debug("Completed HTML text extraction")
+
+	return extracted
 }
 
 func (f *Fetcher) FetchContent(url string) (string, error) {
+	logger.WithField("url", url).Debug("Starting content fetch")
+
 	resp, err := f.client.Get(url)
 	if err != nil {
+		logger.WithFields(logrus.Fields{
+			"url":   url,
+			"error": err,
+		}).Error("Failed to fetch URL")
 		return "", err
 	}
 	defer resp.Body.Close()
 
+	logger.WithFields(logrus.Fields{
+		"url":         url,
+		"statusCode":  resp.StatusCode,
+		"contentType": resp.Header.Get("Content-Type"),
+	}).Debug("Received HTTP response")
+
 	body, err := io.ReadAll(resp.Body)
 	if err != nil {
+		logger.WithFields(logrus.Fields{
+			"url":   url,
+			"error": err,
+		}).Error("Failed to read response body")
 		return "", err
 	}
 
-	return f.extractText(string(body)), nil
+	logger.WithFields(logrus.Fields{
+		"url":        url,
+		"bodyLength": len(body),
+	}).Debug("Successfully read response body")
+
+	content := f.extractText(string(body))
+
+	logger.WithFields(logrus.Fields{
+		"url":             url,
+		"extractedLength": len(content),
+	}).Debug("Completed content fetch and extraction")
+
+	return content, nil
 }
 
 func (f *Fetcher) FetchAllURLs(urls []string) (map[string]string, error) {
+	logger.WithField("urlCount", len(urls)).Debug("Starting batch URL fetch")
+
 	results := make(map[string]string)
+	var failedUrls []string
+
 	for _, url := range urls {
 		content, err := f.FetchContent(url)
 		if err != nil {
-			return nil, err
+			logger.WithFields(logrus.Fields{
+				"url":   url,
+				"error": err,
+			}).Error("Failed to fetch URL in batch")
+			failedUrls = append(failedUrls, url)
+			continue
 		}
 		results[url] = content
 	}
+
+	if len(failedUrls) > 0 {
+		err := fmt.Errorf("failed to fetch %d URLs: %v", len(failedUrls), failedUrls)
+		logger.WithError(err).Error("Batch URL fetch completed with errors")
+		return nil, err
+	}
+
+	logger.WithField("successCount", len(results)).Debug("Successfully completed batch URL fetch")
 	return results, nil
 }

internal/imap/imap.go

@@ -8,11 +8,13 @@ import (
 	"mime/multipart"
 	"net/mail"
 	"paraclub-ai-mailer/config"
+	"paraclub-ai-mailer/internal/logger"
 	"strings"
 	"time"
 
 	"github.com/emersion/go-imap"
 	"github.com/emersion/go-imap/client"
+	"github.com/sirupsen/logrus"
 )
 
 type IMAPClient struct {
@@ -265,85 +267,141 @@ func (ic *IMAPClient) SaveDraft(email Email, response string) error {
 // extractMessageContent attempts to extract just the message content
 // by removing email headers and MIME boundaries
 func extractMessageContent(body string) string {
+	logger.WithField("bodyLength", len(body)).Debug("Starting message content extraction")
+
 	msg, err := mail.ReadMessage(strings.NewReader(body))
 	if err != nil {
-		// Fallback to previous method if parsing fails
+		logger.WithFields(logrus.Fields{
+			"error":      err,
+			"bodyLength": len(body),
+		}).Debug("Failed to parse email message, falling back to simple extraction")
 		return fallbackExtractContent(body)
 	}
 
-	mediaType, params, err := mime.ParseMediaType(msg.Header.Get("Content-Type"))
+	contentTypeHeader := msg.Header.Get("Content-Type")
+	logger.WithField("contentTypeHeader", contentTypeHeader).Debug("Got Content-Type header")
+
+	mediaType, params, err := mime.ParseMediaType(contentTypeHeader)
 	if err != nil {
+		logger.WithFields(logrus.Fields{
+			"error":             err,
+			"contentTypeHeader": contentTypeHeader,
+		}).Debug("Failed to parse Content-Type header, falling back to simple extraction")
 		return fallbackExtractContent(body)
 	}
 
+	logger.WithFields(logrus.Fields{
+		"mediaType": mediaType,
+		"params":    params,
+	}).Debug("Parsed message Content-Type")
+
 	if strings.HasPrefix(mediaType, "multipart/") {
 		boundary := params["boundary"]
 		if boundary == "" {
+			logger.WithField("mediaType", mediaType).Debug("No boundary found in multipart message, falling back to simple extraction")
 			return fallbackExtractContent(body)
 		}
 
+		logger.WithFields(logrus.Fields{
+			"mediaType": mediaType,
+			"boundary":  boundary,
+		}).Debug("Processing multipart message")
+
 		reader := multipart.NewReader(msg.Body, boundary)
 		var textContent string
+		partIndex := 0
 
 		for {
 			part, err := reader.NextPart()
 			if err == io.EOF {
+				logger.Debug("Finished processing all multipart parts")
 				break
 			}
 			if err != nil {
+				logger.WithFields(logrus.Fields{
+					"error":     err,
+					"partIndex": partIndex,
+				}).Debug("Error reading multipart part, falling back to simple extraction")
 				return fallbackExtractContent(body)
 			}
 
-			// Check Content-Type of the part
 			contentType := part.Header.Get("Content-Type")
+			logger.WithFields(logrus.Fields{
+				"partIndex":   partIndex,
+				"contentType": contentType,
+			}).Debug("Processing message part")
+
 			if strings.HasPrefix(contentType, "text/plain") {
 				buf := new(bytes.Buffer)
 				_, err := buf.ReadFrom(part)
 				if err != nil {
+					logger.WithFields(logrus.Fields{
+						"error":     err,
+						"partIndex": partIndex,
+					}).Debug("Failed to read text/plain part")
 					continue
 				}
 				textContent = buf.String()
-				// Convert line endings to HTML breaks
+				logger.WithFields(logrus.Fields{
+					"partIndex":     partIndex,
+					"contentLength": len(textContent),
+				}).Debug("Successfully extracted text/plain content")
 				textContent = strings.ReplaceAll(textContent, "\n", "<br>\n")
 				textContent = strings.ReplaceAll(textContent, "\r\n", "<br>\n")
 				break
 			}
+			partIndex++
 		}
 
 		if textContent != "" {
-			return textContent // Remove TrimSpace to preserve formatting
+			logger.WithField("contentLength", len(textContent)).Debug("Successfully extracted content from multipart message")
+			return textContent
 		}
+		logger.Debug("No text/plain content found in multipart message, trying to read body directly")
 	}
 
-	// For non-multipart messages, just read the body
 	buf := new(bytes.Buffer)
 	_, err = buf.ReadFrom(msg.Body)
 	if err != nil {
+		logger.WithFields(logrus.Fields{
+			"error":     err,
+			"mediaType": mediaType,
+		}).Debug("Failed to read message body, falling back to simple extraction")
 		return fallbackExtractContent(body)
 	}
 
 	content := buf.String()
-	// Convert line endings to HTML breaks
 	content = strings.ReplaceAll(content, "\r\n", "<br>\n")
 	content = strings.ReplaceAll(content, "\n", "<br>\n")
-	return content // Remove TrimSpace to preserve formatting
+	logger.WithFields(logrus.Fields{
+		"contentLength": len(content),
+		"mediaType":     mediaType,
+	}).Debug("Successfully extracted content from message body")
+	return content
 }
 
 // fallbackExtractContent is the previous implementation used as fallback
 func fallbackExtractContent(body string) string {
+	logger.WithField("bodyLength", len(body)).Debug("Using fallback content extraction method")
 	parts := strings.Split(body, "\r\n\r\n")
 	if len(parts) > 1 {
 		content := strings.Join(parts[1:], "\r\n\r\n")
-		// Convert line endings to HTML breaks
 		content = strings.ReplaceAll(content, "\r\n", "<br>\n")
 		content = strings.ReplaceAll(content, "\n", "<br>\n")
-		return content // Remove TrimSpace to preserve formatting
+		logger.WithFields(logrus.Fields{
+			"contentLength": len(content),
+			"partsCount":    len(parts),
+		}).Debug("Successfully extracted content using fallback method")
+		return content
 	}
 	content := body
-	// Convert line endings to HTML breaks
 	content = strings.ReplaceAll(content, "\r\n", "<br>\n")
 	content = strings.ReplaceAll(content, "\n", "<br>\n")
-	return content // Remove TrimSpace to preserve formatting
+	logger.WithFields(logrus.Fields{
+		"contentLength": len(content),
+		"fullBody":      true,
+	}).Debug("Using full body as content in fallback method")
+	return content
 }
 
 func (ic *IMAPClient) MarkAsProcessed(email Email) error {