fix(logger): add logging for request retries

backend/internal/zarinhub/client.go

@@ -7,6 +7,7 @@ import (
 	"errors"
 	"fmt"
 	"io"
+	"log/slog"
 	"net"
 	"net/http"
 	"time"
@@ -27,6 +28,7 @@ type Client struct {
 	tokenProvider TokenProvider
 	maxRetries    int
 	retryWait     func(ctx context.Context, delay time.Duration) bool
+	logger        *slog.Logger
 }
 
 var _ service.CardToIBANClient = (*Client)(nil)
@@ -41,20 +43,34 @@ func NewClient(
 	endpointURL string,
 	tokenProvider TokenProvider,
 	maxRetries int,
+	loggers ...*slog.Logger,
 ) *Client {
 	if maxRetries < 0 {
 		maxRetries = 0
 	}
 
+	var logger *slog.Logger
+	if len(loggers) > 0 && loggers[0] != nil {
+		logger = loggers[0]
+	}
+
 	return &Client{
 		httpClient:    httpClient,
 		endpointURL:   endpointURL,
 		tokenProvider: tokenProvider,
 		maxRetries:    maxRetries,
 		retryWait:     waitForRetry,
+		logger:        logger,
 	}
 }
 
+func (c *Client) log() *slog.Logger {
+	if c.logger != nil {
+		return c.logger
+	}
+	return slog.New(slog.NewTextHandler(io.Discard, nil))
+}
+
 func isRetryable(err error) bool {
 	return errors.Is(err, ErrTimeout) ||
 		errors.Is(err, ErrUnavailable)
@@ -105,6 +121,22 @@ func (c *Client) Convert(
 	}
 
 	for attempt := 0; attempt <= c.maxRetries; attempt++ {
+		if attempt > 0 {
+			c.log().InfoContext(
+				ctx,
+				fmt.Sprintf("[RETRY] zarinhub request attempt %d", attempt),
+				"is_retry", true,
+				"retry_count", attempt,
+			)
+		} else {
+			c.log().InfoContext(
+				ctx,
+				"[INITIAL] zarinhub request",
+				"is_retry", false,
+				"retry_count", 0,
+			)
+		}
+
 		result, err = c.convertOnce(
 			ctx,
 			cardNumber,
@@ -121,6 +153,15 @@ func (c *Client) Convert(
 
 		// We already used all configured retries.
 		if attempt == c.maxRetries {
+			if attempt > 0 {
+				c.log().ErrorContext(
+					ctx,
+					"[RETRY] zarinhub request failed: all retries exhausted",
+					"is_retry", true,
+					"retry_count", attempt,
+					"error", err,
+				)
+			}
 			return result, err
 		}
 
@@ -133,6 +174,14 @@ func (c *Client) Convert(
 		}
 
 		delay := retryDelay(attempt)
+		c.log().WarnContext(
+			ctx,
+			fmt.Sprintf("[RETRY] zarinhub request failed, retrying in %v (retry %d)", delay, attempt+1),
+			"is_retry", true,
+			"next_retry", attempt + 1,
+			"delay_ms", delay.Milliseconds(),
+			"error", err,
+		)
 
 		if !waitFn(ctx, delay) {
 			if errors.Is(ctx.Err(), context.Canceled) {

backend/internal/zarinhub/client_test.go

@@ -1,12 +1,15 @@
 package zarinhub
 
 import (
+	"bytes"
 	"context"
 	"encoding/json"
 	"errors"
 	"fmt"
+	"log/slog"
 	"net/http"
 	"net/http/httptest"
+	"strings"
 	"testing"
 	"time"
 )
@@ -667,3 +670,97 @@ func TestClientStopsRetryOnContextCancellation(t *testing.T) {
 		t.Errorf("request count = %d, want 1", requestCount)
 	}
 }
+
+func TestClientRetryLogging(t *testing.T) {
+	const expectedIBAN = "IR820540102680020817909002"
+	requestCount := 0
+
+	server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		requestCount++
+		if requestCount == 1 {
+			w.WriteHeader(http.StatusServiceUnavailable)
+			fmt.Fprint(w, `{"error":"temporary outage"}`)
+			return
+		}
+
+		w.Header().Set("Content-Type", "application/json")
+		fmt.Fprintf(w, `{
+			"data":{"iban":%q},
+			"meta":{"isSuccess":true,"errors":[]}
+		}`, expectedIBAN)
+	}))
+	defer server.Close()
+
+	var logBuf bytes.Buffer
+	logger := slog.New(slog.NewJSONHandler(&logBuf, nil))
+
+	client := NewClient(
+		&http.Client{Timeout: time.Second},
+		server.URL,
+		&fakeTokenProvider{tokens: []string{"test-token"}},
+		2,
+		logger,
+	)
+	client.retryWait = func(ctx context.Context, delay time.Duration) bool {
+		return true
+	}
+
+	result, err := client.Convert(context.Background(), "6037997512345678")
+	if err != nil {
+		t.Fatalf("Convert() unexpected error = %v", err)
+	}
+	if result.IBAN != expectedIBAN {
+		t.Errorf("IBAN = %q, want %q", result.IBAN, expectedIBAN)
+	}
+
+	logs := logBuf.String()
+
+	if !strings.Contains(logs, "[INITIAL] zarinhub request") {
+		t.Errorf("expected logs to contain '[INITIAL] zarinhub request', got:\n%s", logs)
+	}
+	if !strings.Contains(logs, `"is_retry":false`) {
+		t.Errorf("expected logs to contain '\"is_retry\":false', got:\n%s", logs)
+	}
+
+	if !strings.Contains(logs, "[RETRY] zarinhub request attempt 1") {
+		t.Errorf("expected logs to contain '[RETRY] zarinhub request attempt 1', got:\n%s", logs)
+	}
+	if !strings.Contains(logs, "[RETRY] zarinhub request failed, retrying in") {
+		t.Errorf("expected logs to contain '[RETRY] zarinhub request failed, retrying in', got:\n%s", logs)
+	}
+	if !strings.Contains(logs, `"is_retry":true`) {
+		t.Errorf("expected logs to contain '\"is_retry\":true', got:\n%s", logs)
+	}
+}
+
+func TestClientRetryLoggingExhausted(t *testing.T) {
+	server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		w.WriteHeader(http.StatusServiceUnavailable)
+		fmt.Fprint(w, `{"error":"down"}`)
+	}))
+	defer server.Close()
+
+	var logBuf bytes.Buffer
+	logger := slog.New(slog.NewJSONHandler(&logBuf, nil))
+
+	client := NewClient(
+		&http.Client{Timeout: time.Second},
+		server.URL,
+		&fakeTokenProvider{tokens: []string{"test-token"}},
+		1,
+		logger,
+	)
+	client.retryWait = func(ctx context.Context, delay time.Duration) bool {
+		return true
+	}
+
+	_, err := client.Convert(context.Background(), "6037997512345678")
+	if !errors.Is(err, ErrUnavailable) {
+		t.Fatalf("error = %v, want ErrUnavailable", err)
+	}
+
+	logs := logBuf.String()
+	if !strings.Contains(logs, "[RETRY] zarinhub request failed: all retries exhausted") {
+		t.Errorf("expected logs to contain exhausted retries message, got:\n%s", logs)
+	}
+}