Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
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
6 changes: 6 additions & 0 deletions .changelog/bugfix-clock-skew-response-received-time.json
Original file line number Diff line number Diff line change
@@ -0,0 +1,6 @@
{
"type": "bugfix",
"category": "aws-cpp-sdk-core",
"contributor": "",
"description": "Compute clock skew as the server Date minus the time the response headers were received, instead of the request round-trip midpoint, so long-running operations no longer record a false skew. The curl, CRT and WinHTTP/WinINet clients record the header arrival time; custom HTTP clients that do not set HttpRequest::SetResponseHeadersReceivedTime fall back to the time the request returned."
}
18 changes: 18 additions & 0 deletions src/aws-cpp-sdk-core/include/aws/core/http/HttpRequest.h
Original file line number Diff line number Diff line change
Expand Up @@ -570,6 +570,23 @@ namespace Aws
*/
inline void SetSigningTimestampOverride(const Aws::Utils::DateTime& signingTime) { m_signingTimestampOverride = signingTime; }

/**
* Gets the raw client time (no skew applied) at which the final response's headers arrived for this attempt, if
* the HTTP client recorded it.
*/
inline const Aws::Crt::Optional<Aws::Utils::DateTime>& GetResponseHeadersReceivedTime() const {
return m_responseHeadersReceivedTime;
}
/**
* Records when the response headers arrived, before the body is read. Set by the HTTP client; used as the
* response-received time for clock-skew correction.
*/
inline void SetResponseHeadersReceivedTime(const Aws::Utils::DateTime& time) { m_responseHeadersReceivedTime = time; }
/**
* Clears the response headers received time; called at the start of each attempt.
*/
inline void ClearResponseHeadersReceivedTime() { m_responseHeadersReceivedTime.reset(); }

/**
* Add a request metric
* @param key, HttpClientMetricsKey defined in HttpClientMetrics.cpp
Expand Down Expand Up @@ -631,6 +648,7 @@ namespace Aws
ContinueRequestHandler m_continueRequest;
Aws::String m_signingRegion;
Aws::Crt::Optional<Aws::Utils::DateTime> m_signingTimestampOverride;
Aws::Crt::Optional<Aws::Utils::DateTime> m_responseHeadersReceivedTime;
Aws::String m_signingAccessKey;
Aws::String m_resolvedRemoteHost;
Aws::Monitoring::HttpClientMetricsCollection m_httpRequestMetrics;
Expand Down
12 changes: 9 additions & 3 deletions src/aws-cpp-sdk-core/include/aws/core/internal/ClockSkew.h
Original file line number Diff line number Diff line change
Expand Up @@ -78,9 +78,15 @@ namespace Aws
return Aws::Crt::Optional<std::chrono::milliseconds>{};
}

// Server Date is assumed to be from the round-trip midpoint (NTP offset, RFC 5905 s8).
const int64_t midpointMs = sentMs + (receivedMs - sentMs) / 2;
return Aws::Crt::Optional<std::chrono::milliseconds>(std::chrono::milliseconds{serverMs - midpointMs});
// The server's Date is compared with the moment its response headers reached the client.
return Aws::Crt::Optional<std::chrono::milliseconds>(std::chrono::milliseconds{serverMs - receivedMs});
}

// Time the response headers arrived, if the HTTP client recorded it. Otherwise now (after the body),
// the legacy behaviour.
inline Aws::Utils::DateTime GetTimeResponseReceived(const Aws::Http::HttpRequest& request) {
const auto& stamped = request.GetResponseHeadersReceivedTime();
return stamped.has_value() ? stamped.value() : Aws::Utils::DateTime::Now();
}

// Clock-skew error codes. Matched by CoreErrors enum where one exists; AuthFailure (EC2) has no
Expand Down
9 changes: 6 additions & 3 deletions src/aws-cpp-sdk-core/source/client/AWSClient.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -327,8 +327,9 @@ HttpResponseOutcome AWSClient::AttemptExhaustively(const Aws::Http::URI& uri,

const DateTime attemptSentTime = DateTime::Now();
httpRequest->SetSigningTimestampOverride(attemptSentTime + attemptSkew);
httpRequest->ClearResponseHeadersReceivedTime();
outcome = AttemptOneRequest(httpRequest, request, signerName, signerRegion, signerServiceNameOverride);
const DateTime timeResponseReceived = DateTime::Now();
const DateTime timeResponseReceived = Aws::Internal::GetTimeResponseReceived(*httpRequest);
outcome.SetRetryCount(retries);
if (retries == 0)
{
Expand Down Expand Up @@ -508,8 +509,9 @@ HttpResponseOutcome AWSClient::AttemptExhaustively(const Aws::Http::URI& uri,
};
const DateTime attemptSentTime = DateTime::Now();
httpRequest->SetSigningTimestampOverride(attemptSentTime + attemptSkew);
httpRequest->ClearResponseHeadersReceivedTime();
outcome = AttemptOneRequest(httpRequest, signerName, requestName, signerRegion, signerServiceNameOverride);
const DateTime timeResponseReceived = DateTime::Now();
const DateTime timeResponseReceived = Aws::Internal::GetTimeResponseReceived(*httpRequest);
outcome.SetRetryCount(retries);
if (retries == 0)
{
Expand Down Expand Up @@ -814,6 +816,7 @@ std::shared_ptr<Aws::Http::HttpRequest> AWSClient::StartOneAttemptAsync(const st

context->attemptSentTime = DateTime::Now();
context->httpRequest->SetSigningTimestampOverride(context->attemptSentTime + context->attemptSkew);
context->httpRequest->ClearResponseHeadersReceivedTime();

const char* signerRegion = context->signerRegion ? context->signerRegion->c_str() : nullptr;
const char* signerServiceName = context->signerServiceName ? context->signerServiceName->c_str() : nullptr;
Expand Down Expand Up @@ -912,7 +915,7 @@ Http::HttpClient::AttemptOutcome AWSClient::OnAttemptCompleteAsync(const std::sh
const Aws::AmazonWebServiceRequest& request = *context->request;
HttpResponseOutcome outcome = std::move(outcomeParam);

const DateTime timeResponseReceived = DateTime::Now();
const DateTime timeResponseReceived = Aws::Internal::GetTimeResponseReceived(*context->httpRequest);
outcome.SetRetryCount(context->retries);
if (context->retries == 0)
{
Expand Down
14 changes: 12 additions & 2 deletions src/aws-cpp-sdk-core/source/http/crt/CRTHttpClient.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -202,6 +202,11 @@ void OnClientConnectionAvailableAsync(const std::shared_ptr<Aws::Crt::Http::Http
requestOptions.onIncomingHeaders = [state](Aws::Crt::Http::HttpStream& stream, enum aws_http_header_block block,
const Aws::Crt::Http::HttpHeader* headersArray, std::size_t headersCount) {
OnIncomingHeaders(stream, block, headersArray, headersCount, state->response);
// aws-c-http reports the main block done only when the body starts, so stamp as header lines arrive.
// Written on the event-loop thread and read in the completion callback on that same thread.
if (block == AWS_HTTP_HEADER_BLOCK_MAIN) {
state->request->SetResponseHeadersReceivedTime(Aws::Utils::DateTime::Now());
}
};

requestOptions.onIncomingHeadersBlockDone = [state](Aws::Crt::Http::HttpStream& stream, enum aws_http_header_block block) {
Expand Down Expand Up @@ -292,9 +297,14 @@ class CRTConnection : public Aws::Http::Connection {
Aws::Crt::Http::HttpRequestOptions requestOptions{};
requestOptions.request = crtRequest.get();

requestOptions.onIncomingHeaders = [response](Aws::Crt::Http::HttpStream& stream, enum aws_http_header_block block,
const Aws::Crt::Http::HttpHeader* headersArray, std::size_t headersCount) {
requestOptions.onIncomingHeaders = [request, response](Aws::Crt::Http::HttpStream& stream, enum aws_http_header_block block,
const Aws::Crt::Http::HttpHeader* headersArray, std::size_t headersCount) {
OnIncomingHeaders(stream, block, headersArray, headersCount, response);
// aws-c-http reports the main block done only when the body starts, so stamp as header lines arrive.
// Written on the event-loop thread; the caller reads it only after waiting for stream completion.
if (block == AWS_HTTP_HEADER_BLOCK_MAIN) {
request->SetResponseHeadersReceivedTime(Aws::Utils::DateTime::Now());
}
};

requestOptions.onIncomingHeadersBlockDone = [request, response](Aws::Crt::Http::HttpStream& stream, enum aws_http_header_block block) {
Expand Down
4 changes: 4 additions & 0 deletions src/aws-cpp-sdk-core/source/http/curl/CurlHttpClient.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -277,6 +277,10 @@ static size_t WriteHeader(char* ptr, size_t size, size_t nmemb, void* userdata)
curl_easy_getinfo(context->m_curlHandle, CURLINFO_RESPONSE_CODE, &responseCode);
response->SetResponseCode(static_cast<HttpResponseCode>(responseCode));
AWS_LOGSTREAM_DEBUG(CURL_HTTP_CLIENT_TAG, "Returned http response code " << responseCode);
// Last header block before the body wins, so a 1xx block is overwritten and trailers are ignored.
if (context->m_numBytesResponseReceived == 0) {
context->m_request->SetResponseHeadersReceivedTime(DateTime::Now());
}
auto& headersHandler = context->m_request->GetHeadersReceivedEventHandler();
if (headersHandler)
{
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -191,6 +191,8 @@ bool WinSyncHttpClient::BuildSuccessResponse(const std::shared_ptr<HttpRequest>&
Aws::StringStream ss;
uint64_t read = 0;

// The platform has received the status line and headers by now, and the body is read below.
request->SetResponseHeadersReceivedTime(DateTime::Now());
DoQueryHeaders(hHttpRequest, response, ss, read);

if(readLimiter != nullptr && read > 0)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -495,6 +495,7 @@ std::shared_ptr<Aws::Http::HttpRequest> AwsSmithyClientBase::AttemptOneRequestAs
}
pRequestCtx->m_timeRequestSent = Aws::Utils::DateTime::Now();
pRequestCtx->m_httpRequest->SetSigningTimestampOverride(pRequestCtx->m_timeRequestSent + pRequestCtx->m_attemptSkew);
pRequestCtx->m_httpRequest->ClearResponseHeadersReceivedTime();
SigningOutcome signingOutcome = TracingUtils::MakeCallWithTiming<SigningOutcome>([&]() -> SigningOutcome {
return this->SignHttpRequest(pRequestCtx->m_httpRequest, *pRequestCtx);
},
Expand Down Expand Up @@ -572,7 +573,7 @@ Aws::Http::HttpClient::AttemptOutcome AwsSmithyClientBase::HandleAsyncReply(std:
{
assert(pRequestCtx && httpResponse);

pRequestCtx->m_timeResponseReceived = Aws::Utils::DateTime::Now();
pRequestCtx->m_timeResponseReceived = Aws::Internal::GetTimeResponseReceived(*pRequestCtx->m_httpRequest);
#if defined(AWS_CRT_HTTP_USE_ASYNC_IO)
pRequestCtx->m_serviceCallTimer.reset();
#endif
Expand Down
43 changes: 43 additions & 0 deletions tests/aws-cpp-sdk-core-tests/aws/client/AWSClientTest.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -312,6 +312,49 @@ TEST_F(AWSClientTestSuite, TestClockChangesAfterSkewHasBeenSet)
ASSERT_EQ(1, client->GetRequestAttemptedRetries());
}

TEST_F(AWSClientTestSuite, TestClockSkewUsesResponseHeadersReceivedTime) {
// The HTTP client stamps the time the headers arrived, 3 seconds before the attempt returns (a slow body).
// The skew must be measured from the header time, not from when MakeRequest returned.
mockHttpClient->Reset();
auto makeResponse = []() {
auto httpRequest = CreateHttpRequest(URI("http://www.uri.com/path/to/res"), HttpMethod::HTTP_GET,
Aws::Utils::Stream::DefaultResponseStreamFactoryMethod);
auto httpResponse = Aws::MakeShared<StandardHttpResponse>(ALLOCATION_TAG, httpRequest);
httpResponse->SetResponseCode(HttpResponseCode::OK);
return httpResponse;
};
auto firstResponse = makeResponse();
mockHttpClient->AddResponseToReturn(
firstResponse, [](Aws::IOStream&) -> void {},
[firstResponse](const std::shared_ptr<HttpRequest>& httpRequest) -> void {
// Whole seconds, so the 1 s resolution Date header carries exactly headersReceived + 1h. Back-dating the
// stamp by 3 s stands in for a slow body without sleeping.
const DateTime headersReceived(DateTime::Now().Millis() / 1000 * 1000 - 3000);
httpRequest->SetResponseHeadersReceivedTime(headersReceived);
firstResponse->AddHeader("Date", (headersReceived + std::chrono::hours(1)).ToGmtString(DateFormat::RFC822));
});
mockHttpClient->AddResponseToReturn(makeResponse(), [](Aws::IOStream&) -> void {}, [](const std::shared_ptr<HttpRequest>&) -> void {});

AmazonWebServiceRequestMock request;
auto outcome = client->MakeRequest(request);
AWS_ASSERT_SUCCESS(outcome);

const DateTime before = DateTime::Now();
outcome = client->MakeRequest(request);
const DateTime after = DateTime::Now();
AWS_ASSERT_SUCCESS(outcome);

// The second request is signed at its send time + exactly 1h; that send time lies between before and after.
// Measuring from when MakeRequest returned would give 1h - 3s instead.
const auto& requests = mockHttpClient->GetAllRequestsMade();
ASSERT_EQ(2u, requests.size());
const auto& signingTime = requests.back().GetSigningTimestampOverride();
ASSERT_TRUE(signingTime.has_value());
const DateTime sendTime = signingTime.value() - std::chrono::hours(1);
EXPECT_TRUE(before.Millis() <= sendTime.Millis() && sendTime.Millis() <= after.Millis())
<< "signing time should be the send time + exactly 1h";
}

TEST_F(AWSClientTestSuite, TestRetryHeaders)
{
// The first server time is ahead of us by 1 hour.
Expand Down
91 changes: 79 additions & 12 deletions tests/aws-cpp-sdk-core-tests/resources/clock-skew-test-cases.json
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,7 @@
"response": {
"statusCode": 200,
"headers": {
"Date": "Thu, 01 Jan 2026 00:00:01 GMT"
"Date": "Thu, 01 Jan 2026 00:00:02 GMT"
}
}
}
Expand All @@ -24,6 +24,73 @@
}
]
},
{
"description": "Long-running request does not attribute server processing time to ClientSkew",
"operations": [
{
"initialClientSkew": 0,
"attempts": [
{
"clientTimeAtSend": "2026-01-01T00:00:00Z",
"clientTimeAtReceive": "2026-01-01T00:10:20Z",
"expectedSigningTime": "2026-01-01T00:00:00Z",
"response": {
"statusCode": 200,
"headers": {
"Date": "Thu, 01 Jan 2026 00:10:20 GMT"
}
}
}
],
"expectedClientSkew": 0,
"expectedOutcome": "success",
"documentation": "The request spends 620 seconds in server processing. The midpoint formula would record approximately +310 seconds, but comparing Date to response receipt time records no skew."
},
{
"initialClientSkew": 0,
"attempts": [
{
"clientTimeAtSend": "2026-01-01T00:10:21Z",
"clientTimeAtReceive": "2026-01-01T00:10:22Z",
"expectedSigningTime": "2026-01-01T00:10:21Z",
"response": {
"statusCode": 200,
"headers": {
"Date": "Thu, 01 Jan 2026 00:10:22 GMT"
}
}
}
],
"expectedClientSkew": 0,
"expectedOutcome": "success",
"documentation": "The following operation is signed without a false offset from the preceding long-running request."
}
]
},
{
"description": "Response latency is attributed to ClientSkew",
"operations": [
{
"initialClientSkew": 0,
"attempts": [
{
"clientTimeAtSend": "2026-01-01T00:00:00Z",
"clientTimeAtReceive": "2026-01-01T00:00:02Z",
"expectedSigningTime": "2026-01-01T00:00:00Z",
"response": {
"statusCode": 200,
"headers": {
"Date": "Thu, 01 Jan 2026 00:00:01 GMT"
}
}
}
],
"expectedClientSkew": -1,
"expectedOutcome": "success",
"documentation": "The response is generated when the clocks agree and takes one second to reach the client. Without a server transmit timestamp, that response latency is included in the candidate skew."
}
]
},
{
"description": "Definite clock skew error on first attempt, retry succeeds, ClientSkew persists to next operation",
"operations": [
Expand All @@ -37,7 +104,7 @@
"response": {
"statusCode": 403,
"headers": {
"Date": "Thu, 01 Jan 2026 00:05:01 GMT"
"Date": "Thu, 01 Jan 2026 00:05:02 GMT"
},
"errorCode": "RequestTimeTooSkewed"
}
Expand All @@ -49,7 +116,7 @@
"response": {
"statusCode": 200,
"headers": {
"Date": "Thu, 01 Jan 2026 00:05:03 GMT"
"Date": "Thu, 01 Jan 2026 00:05:04 GMT"
}
}
}
Expand All @@ -67,7 +134,7 @@
"response": {
"statusCode": 200,
"headers": {
"Date": "Thu, 01 Jan 2026 00:06:01 GMT"
"Date": "Thu, 01 Jan 2026 00:06:02 GMT"
}
}
}
Expand All @@ -91,7 +158,7 @@
"response": {
"statusCode": 403,
"headers": {
"Date": "Thu, 01 Jan 2026 00:05:01 GMT"
"Date": "Thu, 01 Jan 2026 00:05:02 GMT"
},
"errorCode": "RequestTimeTooSkewed"
}
Expand Down Expand Up @@ -133,7 +200,7 @@
"response": {
"statusCode": 200,
"headers": {
"Date": "Thu, 01 Jan 2026 00:22:01 GMT"
"Date": "Thu, 01 Jan 2026 00:22:02 GMT"
}
}
}
Expand All @@ -156,7 +223,7 @@
"response": {
"statusCode": 200,
"headers": {
"Date": "Thu, 01 Jan 2026 00:00:01 GMT"
"Date": "Thu, 01 Jan 2026 00:00:02 GMT"
}
}
}
Expand All @@ -179,7 +246,7 @@
"response": {
"statusCode": 400,
"headers": {
"Date": "Thu, 01 Jan 2026 00:02:01 GMT"
"Date": "Thu, 01 Jan 2026 00:02:02 GMT"
},
"errorCode": "InvalidSignatureException"
}
Expand All @@ -204,7 +271,7 @@
"response": {
"statusCode": 400,
"headers": {
"Date": "Thu, 01 Jan 2026 00:05:01 GMT"
"Date": "Thu, 01 Jan 2026 00:05:02 GMT"
},
"errorCode": "InvalidSignatureException"
}
Expand All @@ -216,7 +283,7 @@
"response": {
"statusCode": 200,
"headers": {
"Date": "Thu, 01 Jan 2026 00:05:03 GMT"
"Date": "Thu, 01 Jan 2026 00:05:04 GMT"
}
}
}
Expand Down Expand Up @@ -281,7 +348,7 @@
"response": {
"statusCode": 200,
"headers": {
"Date": "Thu, 01 Jan 2026 16:56:11 GMT"
"Date": "Thu, 01 Jan 2026 16:56:12 GMT"
}
}
}
Expand Down Expand Up @@ -325,7 +392,7 @@
"response": {
"statusCode": 200,
"headers": {
"Date": "Thu, 01 Jan 2026 16:51:11 GMT"
"Date": "Thu, 01 Jan 2026 16:51:12 GMT"
}
}
}
Expand Down
Loading
Loading