Implemented new logging system

client.go

@@ -17,6 +17,7 @@ import (
 	"strconv"
 	"strings"
 	"sync"
+	"text/template"
 	"time"
 
 	"github.com/go-resty/resty/v2"
@@ -120,20 +121,28 @@ type RequestParams struct {
 
 // Generic helper to execute HTTP requests using the
 //
-//nolint:unused
+//nolint:gocognit,unused,funlen
 func (c *httpClient) doRequest(ctx context.Context, method, url string, params RequestParams, mutators ...func(req *http.Request) error) error {
 	// Create a new HTTP request
 	var bodyReader io.Reader
+	var bodyBuffer *bytes.Buffer
+
 	if params.Body != nil {
 		buf := new(bytes.Buffer)
 		if err := json.NewEncoder(buf).Encode(params.Body); err != nil {
+			if c.debug && c.logger != nil {
+				c.logger.Errorf("failed to encode body: %v", err)
+			}
 			return fmt.Errorf("failed to encode body: %w", err)
 		}
 		bodyReader = buf
 	}
 
 	req, err := http.NewRequestWithContext(ctx, method, url, bodyReader)
 	if err != nil {
+		if c.debug && c.logger != nil {
+			c.logger.Errorf("failed to create request: %v", err)
+		}
 		return fmt.Errorf("failed to create request: %w", err)
 	}
 
@@ -147,26 +156,89 @@ func (c *httpClient) doRequest(ctx context.Context, method, url string, params R
 	// Apply mutators
 	for _, mutate := range mutators {
 		if err := mutate(req); err != nil {
+			if c.debug && c.logger != nil {
+				c.logger.Errorf("failed to mutate request: %v", err)
+			}
 			return fmt.Errorf("failed to mutate request: %w", err)
 		}
 	}
 
+	// Log the request if in debug mode
+	if c.debug && c.logger != nil {
+		var reqBody string
+		if bodyBuffer != nil {
+			reqBody = bodyBuffer.String()
+		}
+
+		reqLog := `Sending request:
+Method: {{.Method}}
+URL: {{.URL}}
+Headers: {{.Headers}}
+Body: {{.Body}}`
+		tmpl, _ := template.New("request").Parse(reqLog)
+		var logBuf bytes.Buffer
+		err = tmpl.Execute(&logBuf, map[string]interface{}{
+			"Method":  method,
+			"URL":     url,
+			"Headers": req.Header,
+			"Body":    reqBody,
+		})
+		if err == nil {
+			c.logger.Debugf(logBuf.String())
+		}
+	}
+
 	// Send the request
 	resp, err := c.httpClient.Do(req)
 	if err != nil {
+		if c.debug && c.logger != nil {
+			c.logger.Errorf("failed to send request: %v", err)
+		}
 		return fmt.Errorf("failed to send request: %w", err)
 	}
 	defer resp.Body.Close()
 
 	// Check for HTTP errors
 	resp, err = coupleAPIErrorsHTTP(resp, err)
 	if err != nil {
+		if c.debug && c.logger != nil {
+			c.logger.Errorf("received HTTP error: %v", err)
+		}
 		return err
 	}
 
+	// Log the response if in debug mode
+	if c.debug && c.logger != nil {
+		var respBody bytes.Buffer
+		if _, err := io.Copy(&respBody, resp.Body); err != nil {
+			c.logger.Errorf("failed to read response body: %v", err)
+		}
+
+		respLog := `Received response:
+Status: {{.Status}}
+Headers: {{.Headers}}
+Body: {{.Body}}`
+		tmpl, _ := template.New("response").Parse(respLog)
+		var logBuf bytes.Buffer
+		err = tmpl.Execute(&logBuf, map[string]interface{}{
+			"Status":  resp.Status,
+			"Headers": resp.Header,
+			"Body":    respBody.String(),
+		})
+		if err == nil {
+			c.logger.Debugf(logBuf.String())
+		}
+
+		// Reset the response body reader for actual decoding
+		resp.Body = io.NopCloser(bytes.NewReader(respBody.Bytes()))
+	}
+
 	// Decode the response body
 	if params.Response != nil {
 		if err := json.NewDecoder(resp.Body).Decode(params.Response); err != nil {
+			if c.debug && c.logger != nil {
+				c.logger.Errorf("failed to decode response: %v", err)
+			}
 			return fmt.Errorf("failed to decode response: %w", err)
 		}
 	}
@@ -199,6 +271,20 @@ func (c *Client) SetLogger(logger Logger) *Client {
 	return c
 }
 
+//nolint:unused
+func (c *httpClient) httpSetDebug(debug bool) *httpClient {
+	c.debug = debug
+
+	return c
+}
+
+//nolint:unused
+func (c *httpClient) httpSetLogger(logger httpLogger) *httpClient {
+	c.logger = logger
+
+	return c
+}
+
 // OnBeforeRequest adds a handler to the request body to run before the request is sent
 func (c *Client) OnBeforeRequest(m func(request *Request) error) {
 	c.resty.OnBeforeRequest(func(_ *resty.Client, req *resty.Request) error {

client_http.go

@@ -45,4 +45,6 @@ type httpClient struct {
 	cachedEntries map[string]clientCacheEntry
 	//nolint:unused
 	cachedEntryLock *sync.RWMutex
+	//nolint:unused
+	logger httpLogger
 }

client_test.go

@@ -336,3 +336,93 @@ func TestDoRequest_MutatorError(t *testing.T) {
 		t.Fatalf("expected error %q, got: %v", expectedErr, err)
 	}
 }
+
+func TestDoRequestLogging_Success(t *testing.T) {
+	var logBuffer bytes.Buffer
+	logger := createLogger()
+	logger.l.SetOutput(&logBuffer) // Redirect log output to buffer
+
+	client := &httpClient{
+		httpClient: http.DefaultClient,
+		debug:      true,
+		logger:     logger,
+	}
+
+	handler := func(w http.ResponseWriter, r *http.Request) {
+		w.WriteHeader(http.StatusOK)
+		w.Header().Set("Content-Type", "application/json")
+		_, _ = w.Write([]byte(`{"message":"success"}`))
+	}
+	server := httptest.NewServer(http.HandlerFunc(handler))
+	defer server.Close()
+
+	params := RequestParams{
+		Response: &map[string]string{},
+	}
+
+	err := client.doRequest(context.Background(), http.MethodGet, server.URL, params)
+	if err != nil {
+		t.Fatal(cmp.Diff(nil, err))
+	}
+
+	logInfo := logBuffer.String()
+	logInfoWithoutTimestamps := removeTimestamps(logInfo)
+
+	// Expected logs with templates filled in
+	expectedRequestLog := "DEBUG RESTY Sending request:\nMethod: GET\nURL: " + server.URL + "\nHeaders: map[Accept:[application/json] Content-Type:[application/json]]\nBody: "
+	expectedResponseLog := "DEBUG RESTY Received response:\nStatus: 200 OK\nHeaders: map[Content-Length:[21] Content-Type:[text/plain; charset=utf-8]]\nBody: {\"message\":\"success\"}"
+
+	if !strings.Contains(logInfo, expectedRequestLog) {
+		t.Fatalf("expected log %q not found in logs", expectedRequestLog)
+	}
+	if !strings.Contains(logInfoWithoutTimestamps, expectedResponseLog) {
+		t.Fatalf("expected log %q not found in logs", expectedResponseLog)
+	}
+}
+
+func TestDoRequestLogging_Error(t *testing.T) {
+	var logBuffer bytes.Buffer
+	logger := createLogger()
+	logger.l.SetOutput(&logBuffer) // Redirect log output to buffer
+
+	client := &httpClient{
+		httpClient: http.DefaultClient,
+		debug:      true,
+		logger:     logger,
+	}
+
+	params := RequestParams{
+		Body: map[string]interface{}{
+			"invalid": func() {},
+		},
+	}
+
+	err := client.doRequest(context.Background(), http.MethodPost, "http://example.com", params)
+	expectedErr := "failed to encode body"
+	if err == nil || !strings.Contains(err.Error(), expectedErr) {
+		t.Fatalf("expected error %q, got: %v", expectedErr, err)
+	}
+
+	logInfo := logBuffer.String()
+	expectedLog := "ERROR RESTY failed to encode body"
+
+	if !strings.Contains(logInfo, expectedLog) {
+		t.Fatalf("expected log %q not found in logs", expectedLog)
+	}
+}
+
+func removeTimestamps(log string) string {
+	lines := strings.Split(log, "\n")
+	var filteredLines []string
+	for _, line := range lines {
+		// Find the index of the "Date:" substring
+		if index := strings.Index(line, "Date:"); index != -1 {
+			// Cut off everything after "Date:"
+			trimmedLine := strings.TrimSpace(line[:index])
+			filteredLines = append(filteredLines, trimmedLine+"]")
+		} else {
+			filteredLines = append(filteredLines, line)
+		}
+	}
+	return strings.Join(filteredLines, "\n")
+}

logger.go

@@ -0,0 +1,51 @@
+package linodego
+
+import (
+	"log"
+	"os"
+)
+
+//nolint:unused
+type httpLogger interface {
+	Errorf(format string, v ...interface{})
+	Warnf(format string, v ...interface{})
+	Debugf(format string, v ...interface{})
+}
+
+//nolint:unused
+type logger struct {
+	l *log.Logger
+}
+
+//nolint:unused
+func createLogger() *logger {
+	l := &logger{l: log.New(os.Stderr, "", log.Ldate|log.Lmicroseconds)}
+	return l
+}
+
+//nolint:unused
+var _ httpLogger = (*logger)(nil)
+
+//nolint:unused
+func (l *logger) Errorf(format string, v ...interface{}) {
+	l.output("ERROR RESTY "+format, v...)
+}
+
+//nolint:unused
+func (l *logger) Warnf(format string, v ...interface{}) {
+	l.output("WARN RESTY "+format, v...)
+}
+
+//nolint:unused
+func (l *logger) Debugf(format string, v ...interface{}) {
+	l.output("DEBUG RESTY "+format, v...)
+}
+
+//nolint:unused
+func (l *logger) output(format string, v ...interface{}) { //nolint:goprintffuncname
+	if len(v) == 0 {
+		l.l.Print(format)
+		return
+	}
+	l.l.Printf(format, v...)
+}