Skip to content

Commit a831eec

Browse files
ShocOneShocOne
committed
Add logging capabilities and error handling to the HTTP client
1 parent 74e1bcf commit a831eec

File tree

3 files changed

+124
-105
lines changed

3 files changed

+124
-105
lines changed

‎httpclient/httpclient_request.go‎

Lines changed: 34 additions & 39 deletions
Original file line numberDiff line numberDiff line change
@@ -7,8 +7,8 @@ import (
77
"net/http"
88
"time"
99

10-
"github.com/deploymenttheory/go-api-http-client/errors"
1110
"github.com/deploymenttheory/go-api-http-client/logger"
11+
"github.com/deploymenttheory/go-api-http-client/status"
1212
"github.com/google/uuid"
1313
"go.uber.org/zap"
1414
)
@@ -153,71 +153,66 @@ func (c *Client) executeRequestWithRetries(method, endpoint string, body, out in
153153
headerManager.SetRequestHeaders(endpoint)
154154
headerManager.LogHeaders(c)
155155

156-
// Define a retry deadline based on the client's total retry duration configuration
156+
// Calculate the deadline for all retry attempts based on the client configuration.
157157
totalRetryDeadline := time.Now().Add(c.clientConfig.ClientOptions.TotalRetryDuration)
158158

159+
// Execute the HTTP request with retries
159160
var resp *http.Response
160161
var retryCount int
161-
for time.Now().Before(totalRetryDeadline) { // Check if the current time is before the total retry deadline
162-
req = req.WithContext(ctx)
162+
var requestStartTime = time.Now()
163+
164+
for time.Now().Before(totalRetryDeadline) {
163165
resp, err = c.do(req, log, method, endpoint)
164-
// Check for successful status code
165-
if err == nil && resp.StatusCode >= 200 && resp.StatusCode < 400 {
166-
if resp.StatusCode >= 300 {
167-
log.Warn("Redirect response received", zap.Int("status_code", resp.StatusCode), zap.String("location", resp.Header.Get("Location")))
168-
}
169-
// Handle the response as successful, even if it's a redirect.
166+
167+
// Successful response handling
168+
if err == nil && resp.StatusCode >= 200 && resp.StatusCode < 300 {
169+
log.LogRequestEnd(method, endpoint, resp.StatusCode, time.Since(requestStartTime))
170170
return resp, c.handleSuccessResponse(resp, out, log, method, endpoint)
171171
}
172172

173-
// Leverage TranslateStatusCode for more descriptive error logging
174-
statusMessage := errors.TranslateStatusCode(resp)
175-
176-
// Check for non-retryable errors
177-
if resp != nil && errors.IsNonRetryableStatusCode(resp) {
178-
log.Warn("Non-retryable error received", zap.Int("status_code", resp.StatusCode), zap.String("status_message", statusMessage))
179-
return resp, errors.HandleAPIError(resp, log)
173+
// Log and handle non-retryable errors immediately without retrying
174+
if resp != nil && status.IsNonRetryableStatusCode(resp) {
175+
log.LogError(method, endpoint, resp.StatusCode, err, status.TranslateStatusCode(resp))
176+
return resp, err
180177
}
181178

182-
// Parsing rate limit headers if a rate-limit error is detected
183-
if errors.IsRateLimitError(resp) {
179+
// Handle rate-limiting errors by parsing the 'Retry-After' header and waiting before the next retry
180+
if status.IsRateLimitError(resp) {
184181
waitDuration := parseRateLimitHeaders(resp, log)
185-
if waitDuration > 0 {
186-
log.Warn("Rate limit encountered, waiting before retrying", zap.Duration("waitDuration", waitDuration))
187-
time.Sleep(waitDuration)
188-
continue // Continue to next iteration after waiting
189-
}
182+
log.LogRateLimiting(method, endpoint, resp.Header.Get("Retry-After"), waitDuration)
183+
time.Sleep(waitDuration)
184+
continue
190185
}
191186

192-
// Handling retryable errors with exponential backoff
193-
if errors.IsTransientError(resp) {
187+
// Retry the request for transient errors using exponential backoff with jitter
188+
if status.IsTransientError(resp) {
194189
retryCount++
195190
if retryCount > c.clientConfig.ClientOptions.MaxRetryAttempts {
196-
log.Warn("Max retry attempts reached", zap.String("method", method), zap.String("endpoint", endpoint))
197-
break // Stop retrying if max attempts are reached
191+
// Log max retry attempts reached with structured logging
192+
log.LogError(method, endpoint, resp.StatusCode, err, "Max retry attempts reached")
193+
break
198194
}
199195
waitDuration := calculateBackoff(retryCount)
200-
log.Warn("Retrying request due to transient error", zap.String("method", method), zap.String("endpoint", endpoint), zap.Int("retryCount", retryCount), zap.Duration("waitDuration", waitDuration), zap.Error(err))
201-
time.Sleep(waitDuration) // Wait before retrying
202-
continue // Continue to next iteration after waiting
196+
log.LogRetryAttempt(method, endpoint, retryCount, "Transient error", waitDuration, err)
197+
time.Sleep(waitDuration)
198+
continue
203199
}
204200

205-
// Handle error responses
206-
if err != nil || !errors.IsRetryableStatusCode(resp.StatusCode) {
207-
if apiErr := errors.HandleAPIError(resp, log); apiErr != nil {
208-
err = apiErr
209-
}
210-
log.Error("API error", zap.String("status_message", statusMessage), zap.Error(err))
201+
// Log non-retryable API errors and break the retry loop
202+
if err != nil || !status.IsRetryableStatusCode(resp.StatusCode) {
203+
log.LogError(method, endpoint, resp.StatusCode, err, status.TranslateStatusCode(resp))
211204
break
212205
}
213206
}
214207

215-
// Handles final non-API error.
208+
// Final error handling after all retries are exhausted
216209
if err != nil {
210+
// Log the final error after retries with structured logging
211+
log.LogError(method, endpoint, 0, err, "Final error after retries")
217212
return nil, err
218213
}
219214

220-
return resp, errors.HandleAPIError(resp, log)
215+
return resp, nil
221216
}
222217

223218
// executeRequest executes an HTTP request using the specified method, endpoint, and request body without implementing

‎logger/zaplogger_logfields.go‎

Lines changed: 75 additions & 50 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,3 @@
1-
// zaplogger_logfields.go
21
package logger
32

43
import (
@@ -7,66 +6,92 @@ import (
76
"go.uber.org/zap"
87
)
98

10-
// LogRequestStart logs the initiation of an HTTP request, including the HTTP method, URL, and headers.
11-
// This function is intended to be called at the beginning of an HTTP request lifecycle.
12-
func LogRequestStart(logger *zap.Logger, requestID string, userID string, method string, url string, headers map[string][]string) {
13-
fields := []zap.Field{
14-
zap.String("event", "request_start"),
15-
zap.String("method", method),
16-
zap.String("url", url),
17-
zap.Reflect("headers", headers), // Consider sanitizing or selectively logging headers
9+
// LogRequestStart logs the initiation of an HTTP request if the current log level permits.
10+
func (d *defaultLogger) LogRequestStart(requestID string, userID string, method string, url string, headers map[string][]string) {
11+
if d.logLevel <= LogLevelInfo { // Assuming LogLevelInfo is appropriate for request start messages.
12+
fields := []zap.Field{
13+
zap.String("event", "request_start"),
14+
zap.String("method", method),
15+
zap.String("url", url),
16+
zap.String("request_id", requestID),
17+
zap.String("user_id", userID),
18+
zap.Reflect("headers", headers),
19+
}
20+
d.logger.Info("HTTP request started", fields...)
1821
}
19-
logger.Info("HTTP request started", fields...)
2022
}
2123

22-
// LogRequestEnd logs the completion of an HTTP request, including the HTTP method, URL, status code, and duration.
23-
// This function is intended to be called at the end of an HTTP request lifecycle.
24-
func LogRequestEnd(logger *zap.Logger, method string, url string, statusCode int, duration time.Duration) {
25-
fields := []zap.Field{
26-
zap.String("event", "request_end"),
27-
zap.String("method", method),
28-
zap.String("url", url),
29-
zap.Int("status_code", statusCode),
30-
zap.Duration("duration", duration),
24+
// LogRequestEnd logs the completion of an HTTP request if the current log level permits.
25+
func (d *defaultLogger) LogRequestEnd(method string, url string, statusCode int, duration time.Duration) {
26+
if d.logLevel <= LogLevelInfo { // Assuming LogLevelInfo is appropriate for request end messages.
27+
fields := []zap.Field{
28+
zap.String("event", "request_end"),
29+
zap.String("method", method),
30+
zap.String("url", url),
31+
zap.Int("status_code", statusCode),
32+
zap.Duration("duration", duration),
33+
}
34+
d.logger.Info("HTTP request completed", fields...)
3135
}
32-
logger.Info("HTTP request completed", fields...)
3336
}
3437

35-
// LogError logs an error that occurs during the processing of an HTTP request, including the HTTP method, URL, status code, error message, and stack trace.
36-
// This function is intended to be called when an error is encountered during an HTTP request lifecycle.
37-
func LogError(logger *zap.Logger, method string, url string, statusCode int, err error, stacktrace string) {
38-
fields := []zap.Field{
39-
zap.String("event", "request_error"),
40-
zap.String("method", method),
41-
zap.String("url", url),
42-
zap.Int("status_code", statusCode),
43-
zap.String("error_message", err.Error()),
44-
zap.String("stacktrace", stacktrace),
38+
// LogError logs an error that occurs during the processing of an HTTP request if the current log level permits.
39+
func (d *defaultLogger) LogError(method string, url string, statusCode int, err error, stacktrace string) {
40+
if d.logLevel <= LogLevelError {
41+
fields := []zap.Field{
42+
zap.String("event", "request_error"),
43+
zap.String("method", method),
44+
zap.String("url", url),
45+
zap.Int("status_code", statusCode),
46+
zap.String("error_message", err.Error()),
47+
zap.String("stacktrace", stacktrace),
48+
}
49+
d.logger.Error("Error during HTTP request", fields...)
4550
}
46-
logger.Error("Error during HTTP request", fields...)
4751
}
4852

49-
// LogRetryAttempt logs a retry attempt for an HTTP request, including the HTTP method, URL, attempt number, and reason for the retry.
50-
// This function is intended to be called when an HTTP request is retried.
51-
func LogRetryAttempt(logger *zap.Logger, method string, url string, attempt int, reason string) {
52-
fields := []zap.Field{
53-
zap.String("event", "retry_attempt"),
54-
zap.String("method", method),
55-
zap.String("url", url),
56-
zap.Int("attempt", attempt),
57-
zap.String("reason", reason),
53+
// LogRetryAttempt logs a retry attempt for an HTTP request if the current log level permits, including wait duration and the error that triggered the retry.
54+
func (d *defaultLogger) LogRetryAttempt(method string, url string, attempt int, reason string, waitDuration time.Duration, err error) {
55+
if d.logLevel <= LogLevelWarn { // Assuming LogLevelWarn is appropriate for retry attempt messages.
56+
fields := []zap.Field{
57+
zap.String("event", "retry_attempt"),
58+
zap.String("method", method),
59+
zap.String("url", url),
60+
zap.Int("attempt", attempt),
61+
zap.String("reason", reason),
62+
zap.Duration("waitDuration", waitDuration),
63+
zap.String("error_message", err.Error()),
64+
}
65+
d.logger.Warn("HTTP request retry", fields...)
5866
}
59-
logger.Warn("HTTP request retry", fields...)
6067
}
6168

62-
// LogRateLimiting logs when an HTTP request is rate-limited, including the HTTP method, URL, and the value of the 'Retry-After' header.
63-
// This function is intended to be called when an HTTP request encounters rate limiting.
64-
func LogRateLimiting(logger *zap.Logger, method string, url string, retryAfter string) {
65-
fields := []zap.Field{
66-
zap.String("event", "rate_limited"),
67-
zap.String("method", method),
68-
zap.String("url", url),
69-
zap.String("retry_after", retryAfter),
69+
// LogRateLimiting logs when an HTTP request is rate-limited, including the HTTP method, URL, the value of the 'Retry-After' header, and the actual wait duration.
70+
func (d *defaultLogger) LogRateLimiting(method string, url string, retryAfter string, waitDuration time.Duration) {
71+
if d.logLevel <= LogLevelWarn { // Check if the log level permits warning messages.
72+
fields := []zap.Field{
73+
zap.String("event", "rate_limited"),
74+
zap.String("method", method),
75+
zap.String("url", url),
76+
zap.String("retry_after", retryAfter),
77+
zap.Duration("wait_duration", waitDuration),
78+
}
79+
d.logger.Warn("Rate limit encountered, waiting before retrying", fields...)
80+
}
81+
}
82+
83+
// LogResponse logs details about an HTTP response if the current log level permits.
84+
func (d *defaultLogger) LogResponse(method string, url string, statusCode int, responseBody string, responseHeaders map[string][]string, duration time.Duration) {
85+
if d.logLevel <= LogLevelInfo {
86+
fields := []zap.Field{
87+
zap.String("event", "response_received"),
88+
zap.String("method", method),
89+
zap.String("url", url),
90+
zap.Int("status_code", statusCode),
91+
zap.String("response_body", responseBody),
92+
zap.Reflect("response_headers", responseHeaders),
93+
zap.Duration("duration", duration),
94+
}
95+
d.logger.Info("HTTP response details", fields...)
7096
}
71-
logger.Warn("HTTP request rate-limited", fields...)
7297
}

‎logger/zaplogger_logger.go‎

Lines changed: 15 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ package logger
55
import (
66
"fmt"
77
"os"
8+
"time"
89

910
"go.uber.org/zap"
1011
"go.uber.org/zap/zapcore"
@@ -18,32 +19,24 @@ type defaultLogger struct {
1819
logLevel LogLevel // logLevel determines the current logging level (e.g., DEBUG, INFO, WARN).
1920
}
2021

21-
// SetLevel updates the logging level of the logger. It controls the verbosity of the logs,
22-
// allowing the option to filter out less severe messages based on the specified level.
23-
func (d *defaultLogger) SetLevel(level LogLevel) {
24-
d.logLevel = level
25-
}
26-
2722
// Logger interface with structured logging capabilities at various levels.
2823
type Logger interface {
24+
GetLogLevel() LogLevel
2925
SetLevel(level LogLevel)
26+
With(fields ...zapcore.Field) Logger
3027
Debug(msg string, fields ...zapcore.Field)
3128
Info(msg string, fields ...zapcore.Field)
3229
Warn(msg string, fields ...zapcore.Field)
3330
Error(msg string, fields ...zapcore.Field) error
3431
Panic(msg string, fields ...zapcore.Field)
3532
Fatal(msg string, fields ...zapcore.Field)
36-
With(fields ...zapcore.Field) Logger
37-
GetLogLevel() LogLevel
38-
}
3933

40-
// With adds contextual key-value pairs to the logger, returning a new logger instance with the context.
41-
// This is useful for creating a logger with common fields that should be included in all subsequent log entries.
42-
func (d *defaultLogger) With(fields ...zapcore.Field) Logger {
43-
return &defaultLogger{
44-
logger: d.logger.With(fields...),
45-
logLevel: d.logLevel,
46-
}
34+
LogRequestStart(requestID string, userID string, method string, url string, headers map[string][]string)
35+
LogRequestEnd(method string, url string, statusCode int, duration time.Duration)
36+
LogError(method string, url string, statusCode int, err error, stacktrace string)
37+
LogRetryAttempt(method string, url string, attempt int, reason string, waitDuration time.Duration, err error)
38+
LogRateLimiting(method string, url string, retryAfter string, waitDuration time.Duration)
39+
LogResponse(method string, url string, statusCode int, responseBody string, responseHeaders map[string][]string, duration time.Duration)
4740
}
4841

4942
// GetLogLevel returns the current logging level of the logger. This allows for checking the logger's
@@ -52,6 +45,12 @@ func (d *defaultLogger) GetLogLevel() LogLevel {
5245
return d.logLevel
5346
}
5447

48+
// SetLevel updates the logging level of the logger. It controls the verbosity of the logs,
49+
// allowing the option to filter out less severe messages based on the specified level.
50+
func (d *defaultLogger) SetLevel(level LogLevel) {
51+
d.logLevel = level
52+
}
53+
5554
// Debug logs a message at the Debug level. This level is typically used for detailed troubleshooting
5655
// information that is only relevant during active development or debugging.
5756
func (d *defaultLogger) Debug(msg string, fields ...zapcore.Field) {

0 commit comments

Comments
 (0)