diff --git a/gems/aws-sdk-core/CHANGELOG.md b/gems/aws-sdk-core/CHANGELOG.md index e727dd305e7..2becab62805 100644 --- a/gems/aws-sdk-core/CHANGELOG.md +++ b/gems/aws-sdk-core/CHANGELOG.md @@ -3,6 +3,8 @@ Unreleased Changes * Feature - Support refreshing login credentials in the cached sign-in region, falling back to the configured region when missing or empty. +* Issue - Fix clock skew correction for long-running requests and slow response downloads by using the time response headers are received. + 3.263.0 (2026-10-29) ------------------ diff --git a/gems/aws-sdk-core/lib/aws-sdk-core/plugins/retries/clock_skew.rb b/gems/aws-sdk-core/lib/aws-sdk-core/plugins/retries/clock_skew.rb index 19cf7f0f026..c63d6cbbcdb 100644 --- a/gems/aws-sdk-core/lib/aws-sdk-core/plugins/retries/clock_skew.rb +++ b/gems/aws-sdk-core/lib/aws-sdk-core/plugins/retries/clock_skew.rb @@ -39,7 +39,7 @@ def estimated_skew(endpoint) # Whether a response indicates skew large enough to warrant a retry; records nothing. # @param context [Seahorse::Client::RequestContext] - # @param sent_at [Time, nil] raw (pre-skew) send time, for the midpoint calculation + # @param sent_at [Time, nil] raw (pre-skew) send time, to discard slow requests def clock_skewed?(context, sent_at = nil) candidate = candidate_skew(context, sent_at) !!candidate && candidate.abs > CLOCK_SKEW_THRESHOLD @@ -47,7 +47,7 @@ def clock_skewed?(context, sent_at = nil) # Called on every response; records the skew candidate when one can be computed. # @param context [Seahorse::Client::RequestContext] - # @param sent_at [Time, nil] raw (pre-skew) send time, for the midpoint calculation + # @param sent_at [Time, nil] raw (pre-skew) send time, to discard slow requests def update_clock_correction(context, sent_at = nil) candidate = candidate_skew(context, sent_at) return if candidate.nil? @@ -74,23 +74,22 @@ def update_estimated_skew(context) private # Single source of truth for skew computation; returns a Float skew or nil. + # The candidate is the server Date minus the time the response headers were + # received (the current time if that was not recorded). # @param context [Seahorse::Client::RequestContext] - # @param sent_at [Time, nil] raw (pre-skew) send time; midpoint when present, else server - now + # @param sent_at [Time, nil] raw (pre-skew) send time; used only to discard slow requests # @return [Float, nil] def candidate_skew(context, sent_at = nil) response = context.http_response server_time = server_time(response) # No candidate if the Date header is absent/unparseable or the response was cached. return nil if server_time.nil? || response.headers['age'] - return server_time - Time.now.utc unless sent_at - received_at = Time.now.utc - elapsed = received_at - sent_at + received_at = context.metadata[:response_received_at] || Time.now.utc # Discard if the request was too slow for the measurement to be trusted. - return nil if elapsed > MAX_TRUSTED_REQUEST_DURATION + return nil if sent_at && received_at - sent_at > MAX_TRUSTED_REQUEST_DURATION - # Midpoint formula (NTP clock offset, RFC 5905 section 8). - server_time - (sent_at + (elapsed / 2.0)) + server_time - received_at end ## diff --git a/gems/aws-sdk-core/lib/aws-sdk-core/plugins/retry_errors.rb b/gems/aws-sdk-core/lib/aws-sdk-core/plugins/retry_errors.rb index 1492529c2cd..b68fd0e2752 100644 --- a/gems/aws-sdk-core/lib/aws-sdk-core/plugins/retry_errors.rb +++ b/gems/aws-sdk-core/lib/aws-sdk-core/plugins/retry_errors.rb @@ -177,6 +177,16 @@ class RetryErrors < Seahorse::Client::Plugin DYNAMODB_SERVICES = Set['DynamoDB', 'DynamoDB Streams'].freeze class << self + # @api private + # HTTP retries preserve the listener, so register it only once. + def track_response_time(context) + return unless context.retries.zero? + + context.http_response.on_headers do + context.metadata[:response_received_at] = Time.now.utc + end + end + # TODO: Remove this gate and hardcode new retry behavior once # AWS_NEW_RETRIES_2026 is enabled by default, which includes: # - Default retry_mode to 'standard' @@ -294,6 +304,7 @@ class Handler < Seahorse::Client::Handler def call(context) context.metadata[:retries] ||= {} config = context.config + RetryErrors.track_response_time(context) get_send_token(config) add_retry_headers(context) @@ -451,6 +462,7 @@ def retry_request(context, error) context.config.credentials.refresh! if refresh_credentials?(context, error) context.http_request.body.rewind context.http_response.reset + context.metadata.delete(:response_received_at) call(context) end @@ -492,6 +504,7 @@ def compute_request_ttl(context) class LegacyHandler < Seahorse::Client::Handler def call(context) + RetryErrors.track_response_time(context) response = with_metric { @handler.call(context) } if response.error error_inspector = Retries::ErrorInspector.new( @@ -530,6 +543,7 @@ def retry_request(context, error) context.config.credentials.refresh! if refresh_credentials?(context, error) context.http_request.body.rewind context.http_response.reset + context.metadata.delete(:response_received_at) call(context) end diff --git a/gems/aws-sdk-core/spec/aws/plugins/retries/clock_skew_spec.rb b/gems/aws-sdk-core/spec/aws/plugins/retries/clock_skew_spec.rb index d2fda577fc1..871d0b46343 100644 --- a/gems/aws-sdk-core/spec/aws/plugins/retries/clock_skew_spec.rb +++ b/gems/aws-sdk-core/spec/aws/plugins/retries/clock_skew_spec.rb @@ -10,18 +10,17 @@ module Plugins # @param endpoint [URI, String] the endpoint the request points at # @param server_time [String, nil] the timestamp returned by the server def build_context(endpoint, server_time) - response = double('response', headers: { 'date' => server_time }) - request = double('request', endpoint: endpoint) - - double('context', http_response: response, http_request: request) + build_context_with_headers(endpoint, 'date' => server_time) end - # Builds a context whose response carries arbitrary headers (e.g. 'age'). - def build_context_with_headers(endpoint, headers) + # Builds a context whose response carries arbitrary headers (e.g. 'age') + # and, optionally, the time the response headers were received. + def build_context_with_headers(endpoint, headers, received_at = nil) response = double('response', headers: headers) request = double('request', endpoint: endpoint) + metadata = { response_received_at: received_at } - double('context', http_response: response, http_request: request) + double('context', http_response: response, http_request: request, metadata: metadata) end subject { Retries::ClockSkew.new } @@ -391,20 +390,28 @@ def build_context_with_headers(endpoint, headers) end end - describe 'candidate skew (midpoint + guards)' do - describe '#update_clock_correction with a send time' do - it 'uses the midpoint formula to discount network transit' do - sent_at = Time.now.utc - # server generated its Date 100s ahead of the client, response takes 10s - server_time = (sent_at + 100).httpdate - ctx = build_context_with_headers(endpoint, 'date' => server_time) - allow(Time).to receive(:now).and_return(sent_at.getlocal + 10) + describe 'response headers arrival time' do + let(:t) { Time.utc(2026, 1, 1) } - subject.update_clock_correction(ctx, sent_at) - # midpoint = sent_at + 5s, so skew ~= 100 - 5 = 95s - expect(subject.clock_correction(endpoint)).to be_within(1).of(95) - end + it 'trusts headers received within the duration limit even when the body finishes later' do + allow(Time).to receive(:now).and_return(t + 901) + ctx = build_context_with_headers(endpoint, { 'date' => (t + 4499).httpdate }, t + 899) + subject.update_clock_correction(ctx, t) + + expect(subject.clock_correction(endpoint)).to eq(3600) + end + + it 'uses headers arrival to decide whether skew exceeds the retry threshold' do + allow(Time).to receive(:now).and_return(t + 1000) + ctx = build_context_with_headers(endpoint, { 'date' => (t + 241).httpdate }, t + 2) + + expect(subject.clock_skewed?(ctx, t)).to be(false) + end + end + + describe 'candidate skew (guards)' do + describe '#update_clock_correction with a send time' do it 'discards the candidate when elapsed exceeds the max trusted duration' do sent_at = Time.now.utc server_time = (sent_at + 100).httpdate @@ -461,8 +468,8 @@ def build_context_with_headers(endpoint, headers) end end - describe 'legacy fallback (no send time)' do - it 'computes skew as server_time - now' do + describe 'no headers received time recorded' do + it 'falls back to server_time - now' do server_time = (Time.now.utc + 1000).to_s ctx = build_context_with_headers(endpoint, 'date' => server_time) subject.update_clock_correction(ctx) diff --git a/gems/aws-sdk-core/spec/aws/plugins/retry_errors_legacy_spec.rb b/gems/aws-sdk-core/spec/aws/plugins/retry_errors_legacy_spec.rb index 7e8a91b7902..a24eb6f21e0 100644 --- a/gems/aws-sdk-core/spec/aws/plugins/retry_errors_legacy_spec.rb +++ b/gems/aws-sdk-core/spec/aws/plugins/retry_errors_legacy_spec.rb @@ -225,6 +225,28 @@ module Plugins expect(resp.context.retries).to eq(1) end + it 'retries clock skew errors using headers arrival before body completion' do + t = Time.utc(2026, 1, 1) + config.retry_limit = 1 + handle do |context| + if context.retries.zero? + # Skew is 248s at headers arrival, but only 230s at body completion. + allow(Time).to receive(:now).and_return(t + 2) + context.http_response.signal_headers(403, 'date' => (t + 250).httpdate) + allow(Time).to receive(:now).and_return(t + 20) + resp.error = RetryErrorsSvc::Errors::RequestTimeTooSkewed.new(nil, nil) + else + context.http_response.signal_headers(200, {}) + resp.error = nil + end + context.http_response.signal_done + resp + end + + expect(resp.context.retries).to eq(1) + expect(resp.error).to be_nil + end + it 'retries if endpoint discovery error is detected' do config.api.endpoint_operation = :describe_endpoints DescribeEndpointsRequest = Seahorse::Model::Shapes::StructureShape.new( diff --git a/gems/aws-sdk-core/spec/aws/plugins/retry_errors_spec.rb b/gems/aws-sdk-core/spec/aws/plugins/retry_errors_spec.rb index b198a537304..90166536921 100644 --- a/gems/aws-sdk-core/spec/aws/plugins/retry_errors_spec.rb +++ b/gems/aws-sdk-core/spec/aws/plugins/retry_errors_spec.rb @@ -148,6 +148,81 @@ module Plugins ) expect(c.config.disable_clock_skew_correction).to eq(true) end + + context 'clock skew correction through a client' do + let(:now) { Time.utc(2026, 1, 1) } + let(:send_handler) { double('send handler') } + let(:client) do + Aws::STS::Client.new( + region: 'us-east-1', retry_mode: 'standard', + credentials: Credentials.new('akid', 'secret') + ) + end + let(:endpoint) { 'https://sts.us-east-1.amazonaws.com' } + + before do + allow(Time).to receive(:now).and_return(now) + allow(Kernel).to receive(:sleep) + send_handler = self.send_handler + client.handle(step: :send) { |context| send_handler.call(context) } + end + + def respond(context, received_at:, server_time:, body_finished_at: received_at, error_code: nil) + allow(Time).to receive(:now).and_return(received_at) + context.http_response.signal_headers( + error_code ? 403 : 200, 'date' => server_time.httpdate + ) + allow(Time).to receive(:now).and_return(body_finished_at) + body = if error_code + 'Sender' \ + "#{error_code}m" \ + 'id' + else + '' \ + '123456789012' \ + '' + end + context.http_response.signal_data(body) + context.http_response.signal_done + Seahorse::Client::Response.new(context: context) + end + + it 'replaces a stale correction with zero after a long-running request' do + clock_skew = client.config.clock_skew + clock_skew.send(:set_clock_correction, endpoint, -300) + expect(clock_skew.clock_correction(endpoint)).to eq(-300) + + allow(send_handler).to receive(:call) do |context| + respond(context, received_at: now + 620, server_time: now + 620) + end + + client.get_caller_identity + + expect(client.config.clock_skew.clock_correction(endpoint)).to eq(0) + end + + it 'signs the retry and later operations using headers arrival despite a delayed error body' do + expect(send_handler).to receive(:call).ordered do |context| + expect(context.http_request.headers['X-Amz-Date']).to eq('20260101T000000Z') + respond( + context, received_at: now + 2, server_time: now + 302, + body_finished_at: now + 20, error_code: 'RequestTimeTooSkewed' + ) + end + expect(send_handler).to receive(:call).ordered do |context| + expect(context.http_request.headers['X-Amz-Date']).to eq('20260101T000520Z') + respond(context, received_at: now + 22, server_time: now + 322) + end + expect(send_handler).to receive(:call).ordered do |context| + expect(context.http_request.headers['X-Amz-Date']).to eq('20260101T000600Z') + respond(context, received_at: now + 62, server_time: now + 362) + end + + client.get_caller_identity + allow(Time).to receive(:now).and_return(now + 60) + client.get_caller_identity + end + end end describe RetryErrors::Handler do @@ -184,6 +259,41 @@ module Plugins resp.context.operation = operation end + it 'corrects clock skew using headers arrival before the response body finishes' do + t = Time.utc(2026, 1, 1) + handle do |context| + allow(Time).to receive(:now).and_return((t + 2).getlocal) + context.http_response.signal_headers(200, 'date' => (t + 3602).httpdate) + allow(Time).to receive(:now).and_return((t + 10).getlocal) + context.http_response.signal_data('body') + context.http_response.signal_done + resp + end + + expect(config.clock_skew.clock_correction(resp.context.http_request.endpoint)).to eq(3600) + end + + it 'clears the previous attempt timestamp before receiving retry headers' do + t = Time.utc(2026, 1, 1) + handle do |context| + expect(context.metadata[:response_received_at]).to be_nil + if context.retries.zero? + allow(Time).to receive(:now).and_return((t + 2).getlocal) + context.http_response.signal_headers(500, {}) + resp.error = service_error + else + allow(Time).to receive(:now).and_return((t + 5).getlocal) + context.http_response.signal_headers(200, {}) + resp.error = nil + end + context.http_response.signal_done + resp + end + + expect(resp.context.retries).to eq(1) + expect(resp.context.metadata[:response_received_at]).to eq(t + 5) + end + context 'standard mode' do before(:each) do allow(RetryErrors).to receive(:new_retries?).and_return(true)