diff --git a/client.go b/client.go index d668eb6d3..9c4920185 100644 --- a/client.go +++ b/client.go @@ -17,6 +17,7 @@ import ( "strconv" "strings" "sync" + "text/template" "time" "github.com/go-resty/resty/v2" @@ -48,6 +49,20 @@ const ( APIDefaultCacheExpiration = time.Minute * 15 ) +//nolint:unused +var ( + reqLogTemplate = template.Must(template.New("request").Parse(`Sending request: +Method: {{.Method}} +URL: {{.URL}} +Headers: {{.Headers}} +Body: {{.Body}}`)) + + respLogTemplate = template.Must(template.New("response").Parse(`Received response: +Status: {{.Status}} +Headers: {{.Headers}} +Body: {{.Body}}`)) +) + var envDebug = false // Client is a wrapper around the Resty client @@ -118,59 +133,169 @@ type RequestParams struct { Response any } -// Generic helper to execute HTTP requests using the +// Generic helper to execute HTTP requests using the net/http package // -//nolint:unused +// nolint:unused func (c *httpClient) doRequest(ctx context.Context, method, url string, params RequestParams, mutators ...func(req *http.Request) error) error { - // Create a new HTTP request + req, bodyBuffer, err := c.createRequest(ctx, method, url, params) + if err != nil { + return err + } + + if err := c.applyMutators(req, mutators); err != nil { + return err + } + + if c.debug && c.logger != nil { + c.logRequest(req, method, url, bodyBuffer) + } + + resp, err := c.sendRequest(req) + if err != nil { + return err + } + defer resp.Body.Close() + + if err := c.checkHTTPError(resp); err != nil { + return err + } + + if c.debug && c.logger != nil { + resp, err = c.logResponse(resp) + if err != nil { + return err + } + } + + if params.Response != nil { + if err := c.decodeResponseBody(resp, params.Response); err != nil { + return err + } + } + + return nil +} + +// nolint:unused +func (c *httpClient) createRequest(ctx context.Context, method, url string, params RequestParams) (*http.Request, *bytes.Buffer, error) { 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 { - return fmt.Errorf("failed to encode body: %w", err) + bodyBuffer = new(bytes.Buffer) + if err := json.NewEncoder(bodyBuffer).Encode(params.Body); err != nil { + if c.debug && c.logger != nil { + c.logger.Errorf("failed to encode body: %v", err) + } + return nil, nil, fmt.Errorf("failed to encode body: %w", err) } - bodyReader = buf + bodyReader = bodyBuffer } req, err := http.NewRequestWithContext(ctx, method, url, bodyReader) if err != nil { - return fmt.Errorf("failed to create request: %w", err) + if c.debug && c.logger != nil { + c.logger.Errorf("failed to create request: %v", err) + } + return nil, nil, fmt.Errorf("failed to create request: %w", err) } - // Set default headers req.Header.Set("Content-Type", "application/json") req.Header.Set("Accept", "application/json") if c.userAgent != "" { req.Header.Set("User-Agent", c.userAgent) } - // Apply mutators + return req, bodyBuffer, nil +} + +// nolint:unused +func (c *httpClient) applyMutators(req *http.Request, mutators []func(req *http.Request) error) error { 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) } } + return nil +} + +// nolint:unused +func (c *httpClient) logRequest(req *http.Request, method, url string, bodyBuffer *bytes.Buffer) { + var reqBody string + if bodyBuffer != nil { + reqBody = bodyBuffer.String() + } else { + reqBody = "nil" + } + + var logBuf bytes.Buffer + err := reqLogTemplate.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 +// nolint:unused +func (c *httpClient) sendRequest(req *http.Request) (*http.Response, error) { resp, err := c.httpClient.Do(req) if err != nil { - return fmt.Errorf("failed to send request: %w", err) + if c.debug && c.logger != nil { + c.logger.Errorf("failed to send request: %v", err) + } + return nil, fmt.Errorf("failed to send request: %w", err) } - defer resp.Body.Close() + return resp, nil +} - // Check for HTTP errors - resp, err = coupleAPIErrorsHTTP(resp, err) +// nolint:unused +func (c *httpClient) checkHTTPError(resp *http.Response) error { + _, err := coupleAPIErrorsHTTP(resp, nil) if err != nil { + if c.debug && c.logger != nil { + c.logger.Errorf("received HTTP error: %v", err) + } return err } + return nil +} - // Decode the response body - if params.Response != nil { - if err := json.NewDecoder(resp.Body).Decode(params.Response); err != nil { - return fmt.Errorf("failed to decode response: %w", err) - } +// nolint:unused +func (c *httpClient) logResponse(resp *http.Response) (*http.Response, error) { + var respBody bytes.Buffer + if _, err := io.Copy(&respBody, resp.Body); err != nil { + c.logger.Errorf("failed to read response body: %v", err) } + var logBuf bytes.Buffer + err := respLogTemplate.Execute(&logBuf, map[string]interface{}{ + "Status": resp.Status, + "Headers": resp.Header, + "Body": respBody.String(), + }) + if err == nil { + c.logger.Debugf(logBuf.String()) + } + + resp.Body = io.NopCloser(bytes.NewReader(respBody.Bytes())) + return resp, nil +} + +// nolint:unused +func (c *httpClient) decodeResponseBody(resp *http.Response, response interface{}) error { + if err := json.NewDecoder(resp.Body).Decode(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) + } return nil } @@ -199,6 +324,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 { diff --git a/client_http.go b/client_http.go index e7f4b8f16..a910cb634 100644 --- a/client_http.go +++ b/client_http.go @@ -45,4 +45,6 @@ type httpClient struct { cachedEntries map[string]clientCacheEntry //nolint:unused cachedEntryLock *sync.RWMutex + //nolint:unused + logger httpLogger } diff --git a/client_test.go b/client_test.go index 9b6aa0d59..2b29204d1 100644 --- a/client_test.go +++ b/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") +} diff --git a/logger.go b/logger.go new file mode 100644 index 000000000..5de758591 --- /dev/null +++ b/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...) +}