diff --git a/pkg/appstore/appstore.go b/pkg/appstore/appstore.go index 9e9a0268..cfc3b6b7 100644 --- a/pkg/appstore/appstore.go +++ b/pkg/appstore/appstore.go @@ -81,7 +81,7 @@ func NewAppStore(args Args) AppStore { downloadClient: http.NewClient[downloadResult](clientArgs), platformClient: http.NewClient[platformVersionLookupResult](clientArgs), storefrontClient: http.NewClient[[]byte](clientArgs), - bagClient: http.NewClient[bagResult](clientArgs), + bagClient: http.NewClient[bagResult](http.Args{CookieJar: args.CookieJar, Timeout: http.DefaultAuthenticationTimeout}), ownedAppsClient: http.NewClient[[]byte](clientArgs), httpClient: http.NewClient[interface{}](clientArgs), macDecrypterFactory: defaultMacPackageDecrypterFactory, diff --git a/pkg/appstore/appstore_login.go b/pkg/appstore/appstore_login.go index 03f89dbb..aa2636e8 100644 --- a/pkg/appstore/appstore_login.go +++ b/pkg/appstore/appstore_login.go @@ -1,13 +1,17 @@ package appstore import ( + "context" "encoding/json" "errors" "fmt" + "io" + "net" gohttp "net/http" "net/url" "strconv" "strings" + "syscall" "time" "unicode" @@ -226,6 +230,7 @@ func (t *appstore) login(email, password, authCode, guid, endpoint string, signe func (t *appstore) sendAuthenticationRequest(request http.Request) (http.Result[loginResult], error) { statuses := make([]string, 0, maxAuthenticationRequestAttempts) + onlyHTTP := true sleep := t.authRetrySleep if sleep == nil { @@ -244,27 +249,48 @@ func (t *appstore) sendAuthenticationRequest(request http.Request) (http.Result[ return result, nil } - statuses = append(statuses, strconv.Itoa(status)) + outcome := fmt.Sprintf("HTTP %d", status) + if status == 0 { + outcome = "transport error" + onlyHTTP = false + } + + statuses = append(statuses, outcome) if attempt == maxAuthenticationRequestAttempts { + summary := strings.Join(statuses, ", ") + if onlyHTTP { + // Preserve the existing diagnostic format for HTTP-only failures. + summary = strings.ReplaceAll(summary, ", HTTP ", ", ") + } + return result, fmt.Errorf( - "authentication request failed after %d attempts (HTTP %s): %w", - maxAuthenticationRequestAttempts, strings.Join(statuses, ", "), authenticationRequestError(err), + "authentication request failed after %d attempts (%s): %w", + maxAuthenticationRequestAttempts, summary, authenticationRequestError(err), ) } delay := min(authenticationRetryDelay<<(attempt-1), maxAuthenticationRetryDelay) - var responseErr *http.UnexpectedResponseError + var ( + responseErr *http.UnexpectedResponseError + transportErr *http.TransportError + retryAfter string + ) + if errors.As(err, &responseErr) { - if requested, ok := authenticationRetryAfter(responseErr.RetryAfter, time.Now()); ok { - if requested > maxAuthenticationRetryDelay { - return result, fmt.Errorf("apple requested a wait longer than %s; try again later: %w", maxAuthenticationRetryDelay, err) - } + retryAfter = responseErr.RetryAfter + } else if errors.As(err, &transportErr) { + retryAfter = transportErr.RetryAfter + } - // Retry-After takes precedence over the fallback backoff. - delay = max(requested, time.Second) + if requested, ok := authenticationRetryAfter(retryAfter, time.Now()); ok { + if requested > maxAuthenticationRetryDelay { + return result, fmt.Errorf("apple requested a wait longer than %s; try again later: %w", maxAuthenticationRetryDelay, err) } + + // Retry-After takes precedence over the fallback backoff. + delay = max(requested, time.Second) } sleep(delay) @@ -274,7 +300,21 @@ func (t *appstore) sendAuthenticationRequest(request http.Request) (http.Result[ func retryableAuthenticationError(err error) (int, bool) { var responseErr *http.UnexpectedResponseError if !errors.As(err, &responseErr) { - return 0, false + var transportErr *http.TransportError + if !errors.As(err, &transportErr) || errors.Is(err, context.Canceled) { + return 0, false + } + + // A url.Error can report Timeout false when its cause is wrapped by + // AddHeaderTransport, so inspect each underlying error as well. + for cause := transportErr.Err; cause != nil; cause = errors.Unwrap(cause) { + if networkErr, ok := cause.(net.Error); ok && networkErr.Timeout() { + return 0, true + } + } + + return 0, errors.Is(transportErr, io.EOF) || errors.Is(transportErr, io.ErrUnexpectedEOF) || + errors.Is(transportErr, syscall.ECONNRESET) || errors.Is(transportErr, syscall.EPIPE) } status := responseErr.StatusCode diff --git a/pkg/appstore/authentication_retry_test.go b/pkg/appstore/authentication_retry_test.go index f7536c8a..35e03249 100644 --- a/pkg/appstore/authentication_retry_test.go +++ b/pkg/appstore/authentication_retry_test.go @@ -1,12 +1,19 @@ package appstore import ( + "context" + "crypto/x509" "encoding/base64" "errors" + "fmt" "io" + "net" "net/http" "net/http/cookiejar" "net/http/httptest" + "net/url" + "sync/atomic" + "syscall" "time" "github.com/majd/ipatool/v2/pkg/keychain" @@ -19,6 +26,71 @@ import ( ) var _ = Describe("Authentication recovery", func() { + DescribeTable("bounds transport retries and preserves the underlying error", func(cause error, transportFailure bool, calls int) { + ctrl := gomock.NewController(GinkgoT()) + client := apphttp.NewMockClient[loginResult](ctrl) + failure := cause + if transportFailure { + failure = &apphttp.TransportError{Err: cause} + } + failure = fmt.Errorf("request failed: %w", failure) + client.EXPECT().Send(gomock.Any()).Return(apphttp.Result[loginResult]{}, failure).Times(calls) + var waits []time.Duration + sut := &appstore{loginClient: client, authRetrySleep: func(delay time.Duration) { waits = append(waits, delay) }} + _, err := sut.sendAuthenticationRequest(apphttp.Request{}) + Expect(errors.Is(err, cause)).To(BeTrue()) + if calls == 1 { + Expect(waits).To(BeEmpty()) + } else { + Expect(waits).To(Equal([]time.Duration{10 * time.Second, 20 * time.Second})) + Expect(err.Error()).To(ContainSubstring("after 3 attempts (transport error, transport error, transport error)")) + } + }, + Entry("request deadline", context.DeadlineExceeded, true, 3), + Entry("request deadline wrapped by the header transport", &url.Error{Op: "Post", URL: testAuthEndpoint, Err: fmt.Errorf("failed to make round trip: %w", context.DeadlineExceeded)}, true, 3), + Entry("wrapped DNS timeout", &url.Error{Op: "Post", URL: testAuthEndpoint, Err: &net.DNSError{IsTimeout: true}}, true, 3), + Entry("DNS timeout wrapped by the header transport", &url.Error{Op: "Post", URL: testAuthEndpoint, Err: fmt.Errorf("failed to make round trip: %w", &net.DNSError{IsTimeout: true})}, true, 3), + Entry("connection closed", io.EOF, true, 3), + Entry("truncated response body", io.ErrUnexpectedEOF, true, 3), + Entry("connection reset", &net.OpError{Op: "read", Net: "tcp", Err: syscall.ECONNRESET}, true, 3), + Entry("broken pipe", &net.OpError{Op: "write", Net: "tcp", Err: syscall.EPIPE}, true, 3), + Entry("canceled request", context.Canceled, true, 1), + Entry("canceled request wrapped by the header transport", &url.Error{Op: "Post", URL: testAuthEndpoint, Err: fmt.Errorf("failed to make round trip: %w", context.Canceled)}, true, 1), + Entry("permanent DNS failure", &net.DNSError{IsNotFound: true}, true, 1), + Entry("certificate failure", &url.Error{Op: "Post", URL: testAuthEndpoint, Err: x509.UnknownAuthorityError{}}, true, 1), + Entry("signing or cookie storage timeout", context.DeadlineExceeded, false, 1), + Entry("local EOF", io.EOF, false, 1), + Entry("other transport failure", errors.New("unrecoverable transport error"), true, 1), + ) + + It("shares the attempt budget with HTTP failures and still honors Retry-After", func() { + ctrl := gomock.NewController(GinkgoT()) + client := apphttp.NewMockClient[loginResult](ctrl) + last := &apphttp.TransportError{Err: context.DeadlineExceeded} + gomock.InOrder( + client.EXPECT().Send(gomock.Any()).Return(apphttp.Result[loginResult]{}, &apphttp.TransportError{Err: io.EOF}), + client.EXPECT().Send(gomock.Any()).Return(apphttp.Result[loginResult]{}, &apphttp.UnexpectedResponseError{StatusCode: 503, RetryAfter: "2"}), + client.EXPECT().Send(gomock.Any()).Return(apphttp.Result[loginResult]{}, last), + ) + var waits []time.Duration + sut := &appstore{loginClient: client, authRetrySleep: func(delay time.Duration) { waits = append(waits, delay) }} + _, err := sut.sendAuthenticationRequest(apphttp.Request{}) + Expect(errors.Is(err, last)).To(BeTrue()) + Expect(waits).To(Equal([]time.Duration{10 * time.Second, 2 * time.Second})) + Expect(err.Error()).To(ContainSubstring("after 3 attempts (transport error, HTTP 503, transport error)")) + }) + + It("stops when an incomplete response requests a wait beyond the budget", func() { + ctrl := gomock.NewController(GinkgoT()) + client := apphttp.NewMockClient[loginResult](ctrl) + failure := &apphttp.TransportError{Err: context.DeadlineExceeded, RetryAfter: "3600"} + client.EXPECT().Send(gomock.Any()).Return(apphttp.Result[loginResult]{}, failure).Times(1) + sut := &appstore{loginClient: client, authRetrySleep: func(time.Duration) { Fail("must not sleep") }} + _, err := sut.sendAuthenticationRequest(apphttp.Request{}) + Expect(errors.Is(err, failure)).To(BeTrue()) + Expect(err.Error()).To(ContainSubstring("apple requested a wait longer than 30s")) + }) + DescribeTable("honors Retry-After without exceeding the wait budget", func(status int, header string, calls int, expectedWaits []time.Duration) { ctrl := gomock.NewController(GinkgoT()) @@ -91,6 +163,55 @@ type loginSessionJar struct{ *cookiejar.Jar } func (loginSessionJar) Save() error { return nil } var _ = Describe("Login session continuity", func() { + It("recovers from a body timeout with cookies and a newly signed identical payload", func() { + jar, err := cookiejar.New(nil) + Expect(err).NotTo(HaveOccurred()) + client := apphttp.NewClient[loginResult](apphttp.Args{CookieJar: loginSessionJar{jar}, Authentication: true, Timeout: 250 * time.Millisecond}) + var calls atomic.Int32 + bodies := make(chan []byte, 2) + releaseResponse := make(chan struct{}) + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + defer GinkgoRecover() + call := calls.Add(1) + Expect(r.Method).To(Equal(http.MethodPost)) + body, err := io.ReadAll(r.Body) + Expect(err).NotTo(HaveOccurred()) + bodies <- body + signature, err := base64.StdEncoding.DecodeString(r.Header.Get(apphttp.HeaderAppleActionSignature)) + Expect(err).NotTo(HaveOccurred()) + Expect(signature).To(Equal(body)) + if call == 1 { + http.SetCookie(w, &http.Cookie{Name: "session", Value: "retained", Path: "/"}) + w.Header().Set("Retry-After", "2") + w.WriteHeader(http.StatusTooManyRequests) + _, err = w.Write([]byte("")) + Expect(err).NotTo(HaveOccurred()) + w.(http.Flusher).Flush() + <-releaseResponse + + return + } + Expect(call).To(Equal(int32(2))) + cookie, err := r.Cookie("session") + Expect(err).NotTo(HaveOccurred()) + Expect(cookie.Value).To(Equal("retained")) + _, err = w.Write([]byte("passwordTokentokendsPersonId123")) + Expect(err).NotTo(HaveOccurred()) + })) + DeferCleanup(srv.Close) + DeferCleanup(func() { close(releaseResponse) }) + var waits []time.Duration + sut := &appstore{loginClient: client, authRetrySleep: func(delay time.Duration) { waits = append(waits, delay) }} + signer := &stubActionSigner{} + request := sut.loginRequest("email", "password", "123456", "guid", srv.URL+PrivateAppStoreAPIPathAuth, 1, signer) + result, err := sut.sendAuthenticationRequest(request) + Expect(err).NotTo(HaveOccurred()) + Expect(result.Data.PasswordToken).To(Equal("token")) + Expect(waits).To(Equal([]time.Duration{2 * time.Second})) + Expect(signer.signCalls).To(Equal(2)) + Expect(<-bodies).To(Equal(<-bodies)) + }) + It("retains cookies and the signed payload through retries, a pod redirect and 2FA", func() { ctrl := gomock.NewController(GinkgoT()) jar, err := cookiejar.New(nil) diff --git a/pkg/http/client.go b/pkg/http/client.go index e26b66bb..31d63180 100644 --- a/pkg/http/client.go +++ b/pkg/http/client.go @@ -7,15 +7,19 @@ import ( "errors" "fmt" "io" + "net" "net/http" "regexp" "strings" + "time" "howett.net/plist" ) const appStoreAuthPath = "/WebObjects/MZFinance.woa/wa/authenticate" +const DefaultAuthenticationTimeout = 30 * time.Second + // IsAuthenticationRedirect reports which Store redirects can replay a signed POST. // A 303 explicitly requests a GET and is not part of this authentication flow. func IsAuthenticationRedirect(status int) bool { @@ -51,6 +55,9 @@ type Args struct { CookieJar CookieJar // Authentication isolates login connections and reports only allowlisted response diagnostics. Authentication bool + // Timeout covers the request and response body. Zero uses the authentication + // default for login clients and leaves other clients without an overall limit. + Timeout time.Duration } // UnexpectedResponseError preserves the HTTP status when Apple returns an @@ -96,19 +103,25 @@ func (t *AddHeaderTransport) RoundTrip(req *http.Request) (*http.Response, error func NewClient[R interface{}](args Args) Client[R] { transport := http.DefaultTransport + timeout := args.Timeout if args.Authentication { + if timeout == 0 { + timeout = DefaultAuthenticationTimeout + } + // Keep the cookie jar, but do not share pooled connections with other // Store operations or reuse a connection for the next login attempt. isolated := http.DefaultTransport.(*http.Transport).Clone() isolated.DisableKeepAlives = true + isolated.DialContext = (&net.Dialer{Timeout: 15 * time.Second, KeepAlive: 30 * time.Second}).DialContext transport = isolated } return &client[R]{ authentication: args.Authentication, internalClient: http.Client{ - Timeout: 0, + Timeout: timeout, Jar: args.CookieJar, CheckRedirect: func(req *http.Request, via []*http.Request) error { // Login validates destinations and replays the signed POST itself. @@ -159,7 +172,7 @@ func (c *client[R]) Send(req Request) (Result[R], error) { res, err := c.internalClient.Do(request) if err != nil { - return Result[R]{}, fmt.Errorf("request failed: %w", err) + return Result[R]{}, fmt.Errorf("request failed: %w", &TransportError{Err: err}) } defer res.Body.Close() @@ -186,7 +199,7 @@ func (c *client[R]) Send(req Request) (Result[R], error) { func (c *client[R]) handleRawResponse(res *http.Response) (Result[R], error) { body, err := io.ReadAll(res.Body) if err != nil { - return Result[R]{}, fmt.Errorf("failed to read response body: %w", err) + return Result[R]{}, fmt.Errorf("failed to read response body: %w", &TransportError{Err: err, RetryAfter: res.Header.Get("Retry-After")}) } data, ok := any(body).(R) @@ -222,7 +235,7 @@ func (*client[R]) NewRequest(method, url string, body io.Reader) (*http.Request, func (c *client[R]) handleJSONResponse(res *http.Response) (Result[R], error) { body, err := io.ReadAll(res.Body) if err != nil { - return Result[R]{}, fmt.Errorf("failed to read response body: %w", err) + return Result[R]{}, fmt.Errorf("failed to read response body: %w", &TransportError{Err: err, RetryAfter: res.Header.Get("Retry-After")}) } var data R @@ -241,7 +254,7 @@ func (c *client[R]) handleJSONResponse(res *http.Response) (Result[R], error) { func (c *client[R]) handleXMLResponse(res *http.Response) (Result[R], error) { body, err := io.ReadAll(res.Body) if err != nil { - return Result[R]{}, fmt.Errorf("failed to read response body: %w", err) + return Result[R]{}, fmt.Errorf("failed to read response body: %w", &TransportError{Err: err, RetryAfter: res.Header.Get("Retry-After")}) } if c.authentication && IsAuthenticationRedirect(res.StatusCode) && strings.TrimSpace(res.Header.Get("Location")) == "" { diff --git a/pkg/http/timeout_test.go b/pkg/http/timeout_test.go new file mode 100644 index 00000000..0e825d52 --- /dev/null +++ b/pkg/http/timeout_test.go @@ -0,0 +1,118 @@ +package http + +import ( + "context" + "errors" + "io" + "net/http" + "net/http/cookiejar" + "net/http/httptest" + "strings" + "time" + + . "github.com/onsi/ginkgo/v2" + . "github.com/onsi/gomega" +) + +type timeoutTestTransport func(*http.Request) (*http.Response, error) + +func (t timeoutTestTransport) RoundTrip(request *http.Request) (*http.Response, error) { + return t(request) +} + +type timeoutTestJar struct { + *cookiejar.Jar + saveErr error +} + +func (j timeoutTestJar) Save() error { return j.saveErr } + +var _ = Describe("Request timeouts", func() { + DescribeTable("applies deadlines to bounded clients without limiting downloads", func(args Args, want time.Duration) { + jar, err := cookiejar.New(nil) + Expect(err).NotTo(HaveOccurred()) + args.CookieJar = sessionCookieJar{jar} + sut := NewClient[[]byte](args).(*client[[]byte]) + sut.internalClient.Transport = timeoutTestTransport(func(request *http.Request) (*http.Response, error) { + deadline, ok := request.Context().Deadline() + Expect(ok).To(Equal(want > 0)) + if ok { + Expect(time.Until(deadline)).To(BeNumerically(">", want-time.Second)) + Expect(time.Until(deadline)).To(BeNumerically("<=", want)) + } + + return &http.Response{StatusCode: http.StatusOK, Header: make(http.Header), Body: io.NopCloser(strings.NewReader("body"))}, nil + }) + result, err := sut.Send(Request{URL: "https://example.com", Method: MethodGET, ResponseFormat: ResponseFormatRaw}) + Expect(err).NotTo(HaveOccurred()) + Expect(result.Data).To(Equal([]byte("body"))) + }, + Entry("authentication default", Args{Authentication: true}, 30*time.Second), + Entry("authentication override", Args{Authentication: true, Timeout: 5 * time.Second}, 5*time.Second), + Entry("bounded bag client", Args{Timeout: DefaultAuthenticationTimeout}, 30*time.Second), + Entry("ordinary download client", Args{}, time.Duration(0)), + ) + + DescribeTable("interrupts stalled authentication responses", func(http2, bodyStarted bool) { + jar, err := cookiejar.New(nil) + Expect(err).NotTo(HaveOccurred()) + releaseResponse := make(chan struct{}) + srv := httptest.NewUnstartedServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + defer GinkgoRecover() + Expect(r.ProtoMajor).To(Equal(map[bool]int{false: 1, true: 2}[http2])) + if bodyStarted { + _, err := w.Write([]byte("passwordToken")) + Expect(err).NotTo(HaveOccurred()) + w.(http.Flusher).Flush() + } + // Keep the response incomplete until Send returns; finishing on + // server-side cancellation can race with the client's body read. + <-releaseResponse + })) + srv.EnableHTTP2 = http2 + srv.StartTLS() + DeferCleanup(srv.Close) + DeferCleanup(func() { close(releaseResponse) }) + sut := NewClient[struct{}](Args{Authentication: true, CookieJar: sessionCookieJar{jar}, Timeout: 250 * time.Millisecond}).(*client[struct{}]) + transport := sut.internalClient.Transport.(*AddHeaderTransport).T.(*http.Transport) + transport.TLSClientConfig = srv.Client().Transport.(*http.Transport).TLSClientConfig.Clone() + DeferCleanup(transport.CloseIdleConnections) + _, err = sut.Send(Request{URL: srv.URL + appStoreAuthPath, Method: MethodPOST, ResponseFormat: ResponseFormatXML}) + Expect(err).To(HaveOccurred()) + var transportErr *TransportError + Expect(errors.As(err, &transportErr)).To(BeTrue(), "expected a transport failure, got %v", err) + // A url.Error need not report Timeout when a transport wrapper sits + // between it and the deadline error. Assert the underlying cause. + Expect(errors.Is(err, context.DeadlineExceeded)).To(BeTrue(), "expected a deadline failure, got %v", err) + if bodyStarted { + Expect(err.Error()).To(HavePrefix("failed to read response body:")) + } else { + Expect(err.Error()).To(HavePrefix("request failed:")) + } + }, + Entry("waiting for HTTP/1.1 headers", false, false), + Entry("reading an HTTP/1.1 body", false, true), + Entry("waiting for HTTP/2 headers", true, false), + Entry("reading an HTTP/2 body", true, true), + ) + + DescribeTable("keeps local timeouts distinct from transport failures", func(signing bool) { + jar, err := cookiejar.New(nil) + Expect(err).NotTo(HaveOccurred()) + args := Args{Authentication: true, CookieJar: timeoutTestJar{Jar: jar, saveErr: context.DeadlineExceeded}} + sut := NewClient[struct{}](args).(*client[struct{}]) + sut.internalClient.Transport = timeoutTestTransport(func(request *http.Request) (*http.Response, error) { + Expect(signing).To(BeFalse()) + + return &http.Response{StatusCode: http.StatusOK, Header: make(http.Header), Body: io.NopCloser(strings.NewReader(""))}, nil + }) + request := Request{URL: "https://example.com", Method: MethodPOST, ResponseFormat: ResponseFormatXML} + if signing { + request.ActionSigner = &recordingActionSigner{err: context.DeadlineExceeded} + } + _, err = sut.Send(request) + Expect(errors.Is(err, context.DeadlineExceeded)).To(BeTrue()) + var transportErr *TransportError + Expect(errors.As(err, &transportErr)).To(BeFalse()) + }, Entry("signing", true), Entry("saving cookies", false)) +}) diff --git a/pkg/http/transport_error.go b/pkg/http/transport_error.go new file mode 100644 index 00000000..17fb2fbd --- /dev/null +++ b/pkg/http/transport_error.go @@ -0,0 +1,18 @@ +package http + +// TransportError identifies Send failures while sending a request or reading +// its response, so callers can distinguish them from signing, encoding and +// storage failures before deciding whether to retry. +type TransportError struct { + Err error + // RetryAfter retains Apple's backoff even when reading the response fails. + RetryAfter string +} + +func (e *TransportError) Error() string { + return e.Err.Error() +} + +func (e *TransportError) Unwrap() error { + return e.Err +}