Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

HTTP client round trippers logging, metrics and request id #18

Open
wants to merge 3 commits into
base: master
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
161 changes: 161 additions & 0 deletions httpclient/config.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,161 @@
/*
Copyright © 2024 Acronis International GmbH.

Released under MIT license.
*/

package httpclient

import (
"github.com/acronis/go-appkit/config"
"time"
)

const (
// DefaultLimit is the default limit for rate limiting.
DefaultLimit = 10
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The name DefaultLimit seems too generic for a package-level constant.

Additionally, I’m not convinced that default values are necessary in this case. Please refer to the second part of my next comment for further details.


// DefaultBurst is the default burst for rate limiting.
DefaultBurst = 100

// DefaultWaitTimeout is the default wait timeout for rate limiting.
DefaultWaitTimeout = 10 * time.Second

// configuration properties
cfgKeyRetriesMax = "retries.max_retry_attempts"
Copy link
Member

@vasayxtx vasayxtx Dec 20, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How about renaming retries.max_retry_attempts to retries.maxAttempts? The word "retry" in the middle seems redundant and can be omitted for better readability.

Additionally, consider supporting multiple retry backoff types, such as exponential and constant. You can refer to the BackoffPolicy field in the RetryableRoundTripperOpts struct for implementation details.

cfgKeyRateLimitsLimit = "rate_limits.limit"
cfgKeyRateLimitsBurst = "rate_limits.burst"
cfgKeyRateLimitsWaitTimeout = "rate_limits.wait_timeout"
cfgKeyTimeout = "timeout"
)

// RateLimitConfig represents configuration options for HTTP client rate limits.
type RateLimitConfig struct {
Limit int `mapstructure:"limit"`
Burst int `mapstructure:"burst"`
WaitTimeout time.Duration `mapstructure:"wait_timeout"`
}

// Set is part of config interface implementation.
func (c *RateLimitConfig) Set(dp config.DataProvider) (err error) {
limit, err := dp.GetInt(cfgKeyRateLimitsLimit)
if err != nil {
return err
}
c.Limit = limit
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let's do more validation and return an error for example if the limit is negative.


burst, err := dp.GetInt(cfgKeyRateLimitsBurst)
if err != nil {
return nil
}
c.Burst = burst

waitTimeout, err := dp.GetDuration(cfgKeyRateLimitsWaitTimeout)
if err != nil {
return err
}
c.WaitTimeout = waitTimeout

return nil
}

// SetProviderDefaults is part of config interface implementation.
func (c *RateLimitConfig) SetProviderDefaults(dp config.DataProvider) {
dp.SetDefault(cfgKeyRateLimitsLimit, DefaultLimit)
dp.SetDefault(cfgKeyRateLimitsBurst, DefaultBurst)
dp.SetDefault(cfgKeyRateLimitsWaitTimeout, DefaultWaitTimeout)
}

// TransportOpts returns transport options.
func (c *RateLimitConfig) TransportOpts() RateLimitingRoundTripperOpts {
return RateLimitingRoundTripperOpts{
Burst: c.Burst,
WaitTimeout: c.WaitTimeout,
}
}

// RetriesConfig represents configuration options for HTTP client retries policy.
type RetriesConfig struct {
MaxRetryAttempts int `mapstructure:"max_retry_attempts"`
}

// Set is part of config interface implementation.
func (c *RetriesConfig) Set(dp config.DataProvider) error {
maxRetryAttempts, err := dp.GetInt(cfgKeyRetriesMax)
if err != nil {
return err
}
c.MaxRetryAttempts = maxRetryAttempts

return nil
}

// SetProviderDefaults is part of config interface implementation.
func (c *RetriesConfig) SetProviderDefaults(dp config.DataProvider) {
dp.SetDefault(cfgKeyRetriesMax, DefaultMaxRetryAttempts)
}

// TransportOpts returns transport options.
func (c *RetriesConfig) TransportOpts() RetryableRoundTripperOpts {
return RetryableRoundTripperOpts{MaxRetryAttempts: c.MaxRetryAttempts}
}

// Config represents options for HTTP client configuration.
type Config struct {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please consider the following suggestions:

  1. We usually store internal config structs by value, not by pointer. I.e.:
type Config struct {
	Retries       RetriesConfig   `mapstructure:"retries"`
	RateLimits RateLimitConfig `mapstructure:"rate_limits"`
	Timeout     time.Duration    `mapstructure:"timeout"`
}
  1. All existing Config structs have 2 constructors: NewConfig and NewConfigWithKeyPrefix. Let's do the same for the httpclient.Config too.

  2. Let's add a compile-time check that httpclient.Config implements config.Config and config.KeyPrefixProvider interfaces.

var _ config.Config = (*Config)(nil)
var _ config.KeyPrefixProvider = (*Config)(nil)

Retries *RetriesConfig `mapstructure:"retries"`
RateLimits *RateLimitConfig `mapstructure:"rate_limits"`
Timeout time.Duration `mapstructure:"timeout"`
}

// Set is part of config interface implementation.
func (c *Config) Set(dp config.DataProvider) error {
timeout, err := dp.GetDuration(cfgKeyTimeout)
if err != nil {
return err
}
c.Timeout = timeout

err = c.Retries.Set(config.NewKeyPrefixedDataProvider(dp, ""))
if err != nil {
return err
}

err = c.RateLimits.Set(config.NewKeyPrefixedDataProvider(dp, ""))
if err != nil {
return err
}

return nil
}

// SetProviderDefaults is part of config interface implementation.
func (c *Config) SetProviderDefaults(dp config.DataProvider) {
if c.Retries == nil {
c.Retries = &RetriesConfig{}
}
c.Retries.SetProviderDefaults(dp)

if c.RateLimits == nil {
c.RateLimits = &RateLimitConfig{}
}
c.RateLimits.SetProviderDefaults(dp)

if c.Timeout == 0 {
c.Timeout = DefaultWaitTimeout
}
}

// NewHTTPClientConfig is unified configuration format for HTTP clients.
func NewHTTPClientConfig() *Config {
return &Config{
Retries: &RetriesConfig{
MaxRetryAttempts: DefaultMaxRetryAttempts,
},
RateLimits: &RateLimitConfig{
Limit: DefaultLimit,
Burst: DefaultBurst,
WaitTimeout: DefaultWaitTimeout,
},
Timeout: DefaultWaitTimeout,
}
}
45 changes: 45 additions & 0 deletions httpclient/config_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,45 @@
/*
Copyright © 2024 Acronis International GmbH.

Released under MIT license.
*/

package httpclient

import (
"bytes"
"github.com/acronis/go-appkit/config"
"github.com/stretchr/testify/require"
"testing"
"time"
)

func TestConfigWithLoader(t *testing.T) {
yamlData := []byte(`
retries:
max_retry_attempts: 30
Copy link
Member

@vasayxtx vasayxtx Dec 20, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Configuration parameters should follow camelCase naming conventions to maintain consistency with other packages in go-appkit. Let’s rename them accordingly.

Additionally, the current implementation doesn’t allow enabling the retry mechanism without also enabling rate limiting. I suggest introducing an enabled: true|false flag for both features to provide more flexibility. Alternative option: use rate-limiting round tripper only if the rate limit > 0 and retryable round tripper - only if max retry attempts > 0.

rate_limits:
limit: 300
burst: 3000
wait_timeout: 3s
timeout: 30s
`)

actualConfig := &Config{}
err := config.NewDefaultLoader("").LoadFromReader(bytes.NewReader(yamlData), config.DataTypeYAML, actualConfig)
require.NoError(t, err, "load configuration")

expectedConfig := &Config{
Retries: &RetriesConfig{
MaxRetryAttempts: 30,
},
RateLimits: &RateLimitConfig{
Limit: 300,
Burst: 3000,
WaitTimeout: 3 * time.Second,
},
Timeout: 30 * time.Second,
}

require.Equal(t, expectedConfig, actualConfig, "configuration does not match expected")
}
32 changes: 31 additions & 1 deletion httpclient/httpclient.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,10 @@ Released under MIT license.

package httpclient

import "net/http"
import (
"fmt"
"net/http"
)

// CloneHTTPRequest creates a shallow copy of the request along with a deep copy of the Headers.
func CloneHTTPRequest(req *http.Request) *http.Request {
Expand All @@ -26,3 +29,30 @@ func CloneHTTPHeader(in http.Header) http.Header {
}
return out
}

// MustHTTPClient wraps delegate transports with logging, metrics, rate limiting, retryable, user agent, request id
// and panics if any error occurs.
func MustHTTPClient(cfg *Config, userAgent, reqType string, delegate http.RoundTripper) *http.Client {
Copy link
Member

@vasayxtx vasayxtx Dec 20, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let’s provide both methods:

  • NewHTTPClient: This method returns an error, allowing callers to handle it gracefully.
  • MustNewHTTPClient: This method panics if an error occurs, providing a convenient option for cases where error handling is not necessary.

This approach ensures flexibility for different use cases.

Additionally, I propose introducing two more methods:

  • NewHTTPClientWithOpts
  • MustNewHTTPClientWithOpts

In these methods, the delegate can be within the HTTPClientOpts struct for better extensibility and clarity in configuration.

if delegate == nil {
delegate = http.DefaultTransport
Copy link
Member

@vasayxtx vasayxtx Dec 20, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please use http.DefaultTransport.(*http.Transport).Clone() to avoid any potential side effects.

}

delegate = NewLoggingRoundTripper(delegate, reqType)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I’m not sure it’s a good idea to log all requests unconditionally without providing a way to configure it.

Could we consider adding a configuration like the following?

log:
  slowRequestThreshold: 1s # Log requests taking 1s or longer (warn level).
  mode: none | failed_requests | all_requests # Log modes:
                                 # - none: Disable logging entirely.
                                 # - failed_requests: Log only failed requests (4xx/5xx) at error level.
                                 # - all_requests: Log all requests (2xx at info level, 4xx/5xx at error level).
                                 # Default: failed_requests or none (to be decided).

@andrewesteves, what’s your opinion on this approach?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@vasayxtx i liked the approach and implemented it, just the namings i suggest none, failed and all since it's a logger round tripper for http clients the "requests" suffix could be omitted. is it okay for you?

delegate = NewMetricsRoundTripper(delegate, reqType)

delegate, err := NewRateLimitingRoundTripperWithOpts(
delegate, cfg.RateLimits.Limit, cfg.RateLimits.TransportOpts(),
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It would be a good idea to accept LoggerProvider func(ctx context.Context) log.FieldLogger as an optional parameter in the constructors (NewHTTPClient and MustNewHTTPClient). This provider can then be passed as an option to NewRateLimitingRoundTripperWithOpts.

By default, the LoggerProvider should be set to middleware.GetLoggerFromContext.

Additionally, this LoggerProvider should also be utilized for the LoggingRoundTripper.

)
if err != nil {
panic(fmt.Errorf("create rate limiting round tripper: %w", err))
}

delegate, err = NewRetryableRoundTripperWithOpts(delegate, cfg.Retries.TransportOpts())
if err != nil {
panic(fmt.Errorf("create retryable round tripper: %w", err))
}

delegate = NewUserAgentRoundTripper(delegate, userAgent)
delegate = NewRequestIDRoundTripper(delegate)
return &http.Client{Transport: delegate, Timeout: cfg.Timeout}
}
39 changes: 39 additions & 0 deletions httpclient/httpclient_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,39 @@
/*
Copyright © 2024 Acronis International GmbH.

Released under MIT license.
*/

package httpclient

import (
"context"
"github.com/acronis/go-appkit/httpserver/middleware"
"github.com/acronis/go-appkit/log/logtest"
"github.com/stretchr/testify/require"
"net/http"
"net/http/httptest"
"testing"
)

func TestMustHTTPClientLoggingRoundTripper(t *testing.T) {
server := httptest.NewServer(http.HandlerFunc(func(rw http.ResponseWriter, r *http.Request) {
rw.WriteHeader(http.StatusTeapot)
}))
defer server.Close()

logger := logtest.NewRecorder()
cfg := NewHTTPClientConfig()
client := MustHTTPClient(cfg, "test-agent", "test-request", nil)
ctx := middleware.NewContextWithLogger(context.Background(), logger)
req, err := http.NewRequestWithContext(ctx, http.MethodPost, server.URL, nil)
require.NoError(t, err)

r, err := client.Do(req)
defer func() { _ = r.Body.Close() }()
require.NoError(t, err)
require.NotEmpty(t, logger.Entries())

loggerEntry := logger.Entries()[0]
require.Contains(t, loggerEntry.Text, "external request POST "+server.URL+" req type test-request status code 418")
}
58 changes: 58 additions & 0 deletions httpclient/logging_round_tripper.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,58 @@
/*
Copyright © 2024 Acronis International GmbH.

Released under MIT license.
*/

package httpclient

import (
"fmt"
"github.com/acronis/go-appkit/httpserver/middleware"
"net/http"
"time"
)

// LoggingRoundTripper implements http.RoundTripper for logging requests.
type LoggingRoundTripper struct {
Delegate http.RoundTripper
ReqType string
}

// NewLoggingRoundTripper creates an HTTP transport that log requests.
func NewLoggingRoundTripper(delegate http.RoundTripper, reqType string) http.RoundTripper {
return &LoggingRoundTripper{
Delegate: delegate,
ReqType: reqType,
}
}

// RoundTrip adds logging capabilities to the HTTP transport.
func (rt *LoggingRoundTripper) RoundTrip(r *http.Request) (*http.Response, error) {
ctx := r.Context()
logger := middleware.GetLoggerFromContext(ctx)
start := time.Now()

resp, err := rt.Delegate.RoundTrip(r)
if logger != nil {
common := "external request %s %s req type %s "
elapsed := time.Since(start)

args := []interface{}{r.Method, r.URL.String(), rt.ReqType, elapsed.Seconds(), err}
message := common + "time taken %.3f, err %+v"

if resp != nil {
args = []interface{}{r.Method, r.URL.String(), rt.ReqType, resp.StatusCode, elapsed.Seconds(), err}
message = common + "status code %d, time taken %.3f, err %+v"
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let’s differentiate logs for successfully completed and failed requests. Logging them separately will make it much easier to search for errors in the logs.

For additional suggestions, please refer to my previous comment.

}

logger.Infof(message, args...)

loggingParams := middleware.GetLoggingParamsFromContext(ctx)
if loggingParams != nil {
loggingParams.AddTimeSlotDurationInMs(fmt.Sprintf("external_request_%s_ms", rt.ReqType), elapsed)
}
}

return resp, err
}
Loading