diff --git a/_integration_tests/appstoreconnect_tests/appstoreconnect_test.go b/_integration_tests/appstoreconnect_tests/appstoreconnect_test.go index 0a469c3c..76925c0f 100644 --- a/_integration_tests/appstoreconnect_tests/appstoreconnect_test.go +++ b/_integration_tests/appstoreconnect_tests/appstoreconnect_test.go @@ -10,7 +10,8 @@ import ( func TestListBundleIDs(t *testing.T) { keyID, issuerID, privateKey, enterpriseAccount := getAPIKey(t) - client := appstoreconnect.NewClient(appstoreconnect.NewRetryableHTTPClient(), keyID, issuerID, []byte(privateKey), enterpriseAccount, appstoreconnect.NoOpAnalyticsTracker{}) + tracker := appstoreconnect.NoOpAnalyticsTracker{} + client := appstoreconnect.NewClient(appstoreconnect.NewRetryableHTTPClient(tracker), keyID, issuerID, []byte(privateKey), enterpriseAccount, tracker) response, err := client.Provisioning.ListBundleIDs(&appstoreconnect.ListBundleIDsOptions{}) require.NoError(t, err) diff --git a/autocodesign/devportalclient/appstoreconnect/appstoreconnect.go b/autocodesign/devportalclient/appstoreconnect/appstoreconnect.go index 36aca686..6ee6d5a6 100644 --- a/autocodesign/devportalclient/appstoreconnect/appstoreconnect.go +++ b/autocodesign/devportalclient/appstoreconnect/appstoreconnect.go @@ -73,8 +73,23 @@ type Client struct { } // NewRetryableHTTPClient create a new http client with retry settings. -func NewRetryableHTTPClient() *http.Client { +func NewRetryableHTTPClient(tracker Tracker) *http.Client { client := retry.NewHTTPClient() + + trackingTransport := newTrackingRoundTripper(client.HTTPClient.Transport, tracker) + client.HTTPClient.Transport = trackingTransport + + // RequestLogHook is called before each retry (attemptNum > 0 for retries, 0 for initial request). + // We mark retry attempts in the request context so RoundTrip can track which attempts are retries. + // We use pointer dereference (*req = *...) to modify the request in-place because RequestLogHook + // doesn't return a value - it modifies the request through side effects. This updates the request's + // context field, which will be present when RoundTrip is called immediately after. + client.RequestLogHook = func(_ retryablehttp.Logger, req *http.Request, attemptNum int) { + if attemptNum > 0 { + *req = *trackingTransport.markAsRetry(req) + } + } + client.CheckRetry = func(ctx context.Context, resp *http.Response, err error) (bool, error) { if resp != nil && resp.StatusCode == http.StatusUnauthorized { log.Debugf("Received HTTP 401 (Unauthorized), retrying request...") @@ -115,6 +130,7 @@ func NewRetryableHTTPClient() *http.Client { return shouldRetry, err } + return client.StandardClient() } @@ -245,8 +261,6 @@ func (c *Client) Debugf(format string, v ...interface{}) { // Do ... func (c *Client) Do(req *http.Request, v interface{}) (*http.Response, error) { - startTime := time.Now() - c.Debugf("Request:") if c.EnableDebugLogs { if err := httputil.PrintRequest(req); err != nil { @@ -255,7 +269,6 @@ func (c *Client) Do(req *http.Request, v interface{}) (*http.Response, error) { } resp, err := c.client.Do(req) - duration := time.Since(startTime) c.Debugf("Response:") if c.EnableDebugLogs { @@ -276,13 +289,10 @@ func (c *Client) Do(req *http.Request, v interface{}) (*http.Response, error) { }() if err := checkResponse(resp); err != nil { - c.tracker.TrackAPIRequest(req.Method, req.URL.Host, req.URL.Path, resp.StatusCode, duration) c.tracker.TrackAPIError(req.Method, req.URL.Host, req.URL.Path, resp.StatusCode, err.Error()) return resp, err } - c.tracker.TrackAPIRequest(req.Method, req.URL.Host, req.URL.Path, resp.StatusCode, duration) - if v != nil { decErr := json.NewDecoder(resp.Body).Decode(v) if decErr == io.EOF { diff --git a/autocodesign/devportalclient/appstoreconnect/appstoreconnect_test.go b/autocodesign/devportalclient/appstoreconnect/appstoreconnect_test.go index bef0a6fe..1b78cd00 100644 --- a/autocodesign/devportalclient/appstoreconnect/appstoreconnect_test.go +++ b/autocodesign/devportalclient/appstoreconnect/appstoreconnect_test.go @@ -17,7 +17,8 @@ import ( ) func TestNewClient(t *testing.T) { - got := NewClient(NewRetryableHTTPClient(), "keyID", "issuerID", []byte{}, false, NoOpAnalyticsTracker{}) + tracker := NoOpAnalyticsTracker{} + got := NewClient(NewRetryableHTTPClient(tracker), "keyID", "issuerID", []byte{}, false, tracker) require.Equal(t, "appstoreconnect-v1", got.audience) @@ -27,7 +28,8 @@ func TestNewClient(t *testing.T) { } func TestNewEnterpriseClient(t *testing.T) { - got := NewClient(NewRetryableHTTPClient(), "keyID", "issuerID", []byte{}, true, NoOpAnalyticsTracker{}) + tracker := NoOpAnalyticsTracker{} + got := NewClient(NewRetryableHTTPClient(tracker), "keyID", "issuerID", []byte{}, true, tracker) require.Equal(t, "apple-developer-enterprise-v1", got.audience) @@ -48,6 +50,7 @@ type apiRequestRecord struct { endpoint string statusCode int duration time.Duration + isRetry bool } type apiErrorRecord struct { @@ -58,13 +61,14 @@ type apiErrorRecord struct { errorMessage string } -func (m *mockAnalyticsTracker) TrackAPIRequest(method, host, endpoint string, statusCode int, duration time.Duration) { +func (m *mockAnalyticsTracker) TrackAPIRequest(method, host, endpoint string, statusCode int, duration time.Duration, isRetry bool) { m.apiRequests = append(m.apiRequests, apiRequestRecord{ method: method, host: host, endpoint: endpoint, statusCode: statusCode, duration: duration, + isRetry: isRetry, }) } @@ -93,6 +97,11 @@ func (m *mockHTTPClient) Do(req *http.Request) (*http.Response, error) { return m.resp, m.err } +func (m *mockHTTPClient) RoundTrip(req *http.Request) (*http.Response, error) { + m.called = true + return m.resp, m.err +} + func TestTracking(t *testing.T) { t.Run("successful request", func(t *testing.T) { mockTracker := &mockAnalyticsTracker{} @@ -103,8 +112,11 @@ func TestTracking(t *testing.T) { })) defer server.Close() + httpClient := &http.Client{} + httpClient.Transport = newTrackingRoundTripper(httpClient.Transport, mockTracker) + client := &Client{ - client: &http.Client{}, + client: httpClient, tracker: mockTracker, } @@ -132,7 +144,7 @@ func TestTracking(t *testing.T) { t.Run("error response", func(t *testing.T) { mockTracker := &mockAnalyticsTracker{} - mockHTTPClient := &mockHTTPClient{ + mockTransport := &mockHTTPClient{ resp: &http.Response{ StatusCode: 400, Body: io.NopCloser(strings.NewReader(`{"errors": [{"code": "PARAMETER_ERROR.INVALID", "title": "Invalid parameter"}]}`)), @@ -140,8 +152,11 @@ func TestTracking(t *testing.T) { }, } + httpClient := &http.Client{} + httpClient.Transport = newTrackingRoundTripper(mockTransport, mockTracker) + client := &Client{ - client: mockHTTPClient, + client: httpClient, tracker: mockTracker, } @@ -150,7 +165,7 @@ func TestTracking(t *testing.T) { _, err = client.Do(req, nil) require.Error(t, err, "Expected error due to 400 Bad Request response") - require.True(t, mockHTTPClient.called, "Expected HTTP client to be called") + require.True(t, mockTransport.called, "Expected HTTP client to be called") require.Len(t, mockTracker.apiRequests, 1, "Expected 1 (failed) API requests tracked") require.Len(t, mockTracker.apiErrors, 1, "Expected 1 API error tracked") @@ -163,12 +178,15 @@ func TestTracking(t *testing.T) { t.Run("network error", func(t *testing.T) { mockTracker := &mockAnalyticsTracker{} - mockHTTPClient := &mockHTTPClient{ + mockTransport := &mockHTTPClient{ err: errors.New("network connection failed"), } + httpClient := &http.Client{} + httpClient.Transport = newTrackingRoundTripper(mockTransport, mockTracker) + client := &Client{ - client: mockHTTPClient, + client: httpClient, tracker: mockTracker, } @@ -177,12 +195,12 @@ func TestTracking(t *testing.T) { _, err = client.Do(req, nil) require.Error(t, err) - require.Len(t, mockTracker.apiRequests, 0, "Expected 0 API requests tracked") + require.Len(t, mockTracker.apiRequests, 1, "Expected 1 API request tracked (even though it failed)") require.Len(t, mockTracker.apiErrors, 1, "Expected 1 API error tracked") record := mockTracker.apiErrors[0] require.Equal(t, "GET", record.method) require.Equal(t, 0, record.statusCode) - require.Equal(t, "network connection failed", record.errorMessage) + require.Contains(t, record.errorMessage, "network connection failed") }) } diff --git a/autocodesign/devportalclient/appstoreconnect/roundtripper.go b/autocodesign/devportalclient/appstoreconnect/roundtripper.go new file mode 100644 index 00000000..a6aaf2a4 --- /dev/null +++ b/autocodesign/devportalclient/appstoreconnect/roundtripper.go @@ -0,0 +1,59 @@ +package appstoreconnect + +import ( + "context" + "net/http" + "time" +) + +// trackingRoundTripper wraps an http.RoundTripper and tracks metrics for each HTTP attempt, +// including retries. It measures per-attempt duration without retry wait times included, +// allowing accurate tracking even when requests are retried due to rate limits or other errors. +type trackingRoundTripper struct { + wrapped http.RoundTripper + tracker Tracker +} + +// isRetryContextKey is used to store whether a request is a retry attempt in the request context. +type isRetryContextKey struct{} + +func newTrackingRoundTripper(wrapped http.RoundTripper, tracker Tracker) *trackingRoundTripper { + if wrapped == nil { + wrapped = http.DefaultTransport + } + return &trackingRoundTripper{ + wrapped: wrapped, + tracker: tracker, + } +} + +// markAsRetry stores a flag in the request context indicating this is a retry attempt. +// It returns a new request with the updated context. This approach avoids shared state +// between concurrent requests (e.g., multiple POSTs to the same endpoint with different bodies). +func (t *trackingRoundTripper) markAsRetry(req *http.Request) *http.Request { + ctx := context.WithValue(req.Context(), isRetryContextKey{}, true) + return req.WithContext(ctx) +} + +// RoundTrip executes an HTTP request and tracks its duration and retry status. +// Each HTTP attempt (including retries) generates a separate metric event, allowing +// accurate alerting based on individual response times rather than aggregate times +// that include retry backoff delays. +func (t *trackingRoundTripper) RoundTrip(req *http.Request) (*http.Response, error) { + // Check if this request was marked as a retry by RequestLogHook + isRetry := req.Context().Value(isRetryContextKey{}) != nil + + startTime := time.Now() + resp, err := t.wrapped.RoundTrip(req) + duration := time.Since(startTime) + + statusCode := 0 + if resp != nil { + statusCode = resp.StatusCode + } + + // Track this attempt with its actual duration (no retry waits included) + t.tracker.TrackAPIRequest(req.Method, req.URL.Host, req.URL.Path, statusCode, duration, isRetry) + + return resp, err +} diff --git a/autocodesign/devportalclient/appstoreconnect/roundtripper_test.go b/autocodesign/devportalclient/appstoreconnect/roundtripper_test.go new file mode 100644 index 00000000..63a057ca --- /dev/null +++ b/autocodesign/devportalclient/appstoreconnect/roundtripper_test.go @@ -0,0 +1,110 @@ +package appstoreconnect + +import ( + "net/http" + "net/http/httptest" + "sync" + "testing" + "time" + + "github.com/stretchr/testify/require" +) + +type attemptTracker struct { + mu sync.Mutex + attempts []attemptRecord +} + +type attemptRecord struct { + method string + host string + endpoint string + statusCode int + duration time.Duration + isRetry bool +} + +func (a *attemptTracker) TrackAPIRequest(method, host, endpoint string, statusCode int, duration time.Duration, isRetry bool) { + a.mu.Lock() + defer a.mu.Unlock() + a.attempts = append(a.attempts, attemptRecord{ + method: method, + host: host, + endpoint: endpoint, + statusCode: statusCode, + duration: duration, + isRetry: isRetry, + }) +} + +func (a *attemptTracker) TrackAPIError(method, host, endpoint string, statusCode int, errorMessage string) { +} + +func (a *attemptTracker) TrackAuthError(errorMessage string) { +} + +func TestTrackingRoundTripper(t *testing.T) { + t.Run("tracks single successful request", func(t *testing.T) { + tracker := &attemptTracker{} + + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusOK) + })) + defer server.Close() + + transport := newTrackingRoundTripper(http.DefaultTransport, tracker) + client := &http.Client{Transport: transport} + + req, err := http.NewRequest("GET", server.URL+"/test", nil) + require.NoError(t, err) + + resp, err := client.Do(req) + require.NoError(t, err) + require.Equal(t, http.StatusOK, resp.StatusCode) + + tracker.mu.Lock() + defer tracker.mu.Unlock() + + require.Len(t, tracker.attempts, 1) + require.False(t, tracker.attempts[0].isRetry) + require.Equal(t, http.StatusOK, tracker.attempts[0].statusCode) + }) + + t.Run("tracks multiple attempts for same request", func(t *testing.T) { + tracker := &attemptTracker{} + attemptCount := 0 + + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + attemptCount++ + if attemptCount < 3 { + w.WriteHeader(http.StatusTooManyRequests) + } else { + w.WriteHeader(http.StatusOK) + } + })) + defer server.Close() + + retryableClient := NewRetryableHTTPClient(tracker) + + req, err := http.NewRequest("GET", server.URL+"/test", nil) + require.NoError(t, err) + + resp, err := retryableClient.Do(req) + require.NoError(t, err) + require.Equal(t, http.StatusOK, resp.StatusCode) + + tracker.mu.Lock() + defer tracker.mu.Unlock() + + require.Len(t, tracker.attempts, 3, "Expected 3 attempts to be tracked") + + require.False(t, tracker.attempts[0].isRetry) + require.Equal(t, http.StatusTooManyRequests, tracker.attempts[0].statusCode) + + require.True(t, tracker.attempts[1].isRetry) + require.Equal(t, http.StatusTooManyRequests, tracker.attempts[1].statusCode) + + require.True(t, tracker.attempts[2].isRetry) + require.Equal(t, http.StatusOK, tracker.attempts[2].statusCode) + }) +} diff --git a/autocodesign/devportalclient/appstoreconnect/tracker.go b/autocodesign/devportalclient/appstoreconnect/tracker.go index 4e8e0785..07db934b 100644 --- a/autocodesign/devportalclient/appstoreconnect/tracker.go +++ b/autocodesign/devportalclient/appstoreconnect/tracker.go @@ -9,8 +9,8 @@ import ( // Tracker defines the interface for tracking App Store Connect API usage and errors. type Tracker interface { - // TrackAPIRequest tracks one completed API request (even if it failed) - TrackAPIRequest(method, host, endpoint string, statusCode int, duration time.Duration) + // TrackAPIRequest tracks one HTTP request+response. This is called for each individual attempt in case of automatic retries. + TrackAPIRequest(method, host, endpoint string, statusCode int, duration time.Duration, isRetry bool) // TrackAPIError tracks a failed API request with error details TrackAPIError(method, host, endpoint string, statusCode int, errorMessage string) @@ -23,7 +23,7 @@ type Tracker interface { type NoOpAnalyticsTracker struct{} // TrackAPIRequest ... -func (n NoOpAnalyticsTracker) TrackAPIRequest(method, host, endpoint string, statusCode int, duration time.Duration) { +func (n NoOpAnalyticsTracker) TrackAPIRequest(method, host, endpoint string, statusCode int, duration time.Duration, isRetry bool) { } // TrackAPIError ... @@ -48,7 +48,7 @@ func NewDefaultTracker(tracker analytics.Tracker, envRepo env.Repository) *Defau } // TrackAPIRequest ... -func (d *DefaultTracker) TrackAPIRequest(method, host, endpoint string, statusCode int, duration time.Duration) { +func (d *DefaultTracker) TrackAPIRequest(method, host, endpoint string, statusCode int, duration time.Duration, isRetry bool) { d.tracker.Enqueue("step_appstoreconnect_request", analytics.Properties{ "build_slug": d.envRepo.Get("BITRISE_BUILD_SLUG"), "step_execution_id": d.envRepo.Get("BITRISE_STEP_EXECUTION_ID"), @@ -57,6 +57,7 @@ func (d *DefaultTracker) TrackAPIRequest(method, host, endpoint string, statusCo "endpoint": endpoint, "status_code": statusCode, "duration_ms": duration.Truncate(time.Millisecond).Milliseconds(), + "is_retry": isRetry, }) } diff --git a/autocodesign/devportalclient/devportalclient.go b/autocodesign/devportalclient/devportalclient.go index 495cdee8..ab13c88f 100644 --- a/autocodesign/devportalclient/devportalclient.go +++ b/autocodesign/devportalclient/devportalclient.go @@ -77,7 +77,7 @@ func (f Factory) Create(credentials devportalservice.Credentials, teamID string) var devportalClient autocodesign.DevPortalClient tracker := appstoreconnect.NewDefaultTracker(analytics.NewDefaultTracker(f.logger), env.NewRepository()) if credentials.APIKey != nil { - httpClient := appstoreconnect.NewRetryableHTTPClient() + httpClient := appstoreconnect.NewRetryableHTTPClient(tracker) client := appstoreconnect.NewClient( httpClient, credentials.APIKey.KeyID,