Test both synchronous and asynchronous DTLS retransmit. The two modes are quite different. One of them requires the BIO honor an extra BIO_ctrl. Also add an explanation at the top of addDTLSRetransmitTests for how these tests work. The description is scattered across many different places. BUG=63 Change-Id: Iff4cdd1fbf4f4439ae0c293f565eb6780c7c84f9 Reviewed-on: https://boringssl-review.googlesource.com/8121 Reviewed-by: David Benjamin <davidben@google.com>
diff --git a/include/openssl/bio.h b/include/openssl/bio.h index df41f0f..5416c65 100644 --- a/include/openssl/bio.h +++ b/include/openssl/bio.h
@@ -587,8 +587,12 @@ #define BIO_CTRL_DGRAM_MTU_EXCEEDED 43 /* check whether the MTU was exceed in the previous write operation. */ -#define BIO_CTRL_DGRAM_SET_NEXT_TIMEOUT \ - 45 /* Next DTLS handshake timeout to adjust socket timeouts */ +/* BIO_CTRL_DGRAM_SET_NEXT_TIMEOUT sets a read deadline to drive + * retransmits. The |parg| argument to |BIO_ctrl| will be a pointer to a + * |timeval| struct. If the structure is all zeros, it clears the read + * deadline. Otherwise, |BIO_read| must fail with a temporary error + * (e.g. |EAGAIN|) after the deadline. */ +#define BIO_CTRL_DGRAM_SET_NEXT_TIMEOUT 45 #define BIO_CTRL_DGRAM_GET_PEER 46
diff --git a/ssl/test/bssl_shim.cc b/ssl/test/bssl_shim.cc index 519736d..eadc27d 100644 --- a/ssl/test/bssl_shim.cc +++ b/ssl/test/bssl_shim.cc
@@ -36,6 +36,7 @@ #pragma comment(lib, "Ws2_32.lib") #endif +#include <assert.h> #include <inttypes.h> #include <string.h> @@ -81,19 +82,10 @@ } struct TestState { - TestState() { - // MSVC cannot initialize these inline. - memset(&clock, 0, sizeof(clock)); - memset(&clock_delta, 0, sizeof(clock_delta)); - } - // async_bio is async BIO which pauses reads and writes. BIO *async_bio = nullptr; - // clock is the current time for the SSL connection. - timeval clock; - // clock_delta is how far the clock advanced in the most recent failed - // |BIO_read|. - timeval clock_delta; + // packeted_bio is the packeted BIO which simulates read timeouts. + BIO *packeted_bio = nullptr; ScopedEVP_PKEY channel_id; bool cert_ready = false; ScopedSSL_SESSION session; @@ -553,7 +545,7 @@ } static void CurrentTimeCallback(const SSL *ssl, timeval *out_clock) { - *out_clock = GetTestState(ssl)->clock; + *out_clock = PacketedBioGetClock(GetTestState(ssl)->packeted_bio); } static void ChannelIdCallback(SSL *ssl, EVP_PKEY **out_pkey) { @@ -890,24 +882,15 @@ const TestConfig *config = GetTestConfig(ssl); TestState *test_state = GetTestState(ssl); - if (test_state->clock_delta.tv_usec != 0 || - test_state->clock_delta.tv_sec != 0) { - // Process the timeout and retry. - test_state->clock.tv_usec += test_state->clock_delta.tv_usec; - test_state->clock.tv_sec += test_state->clock.tv_usec / 1000000; - test_state->clock.tv_usec %= 1000000; - test_state->clock.tv_sec += test_state->clock_delta.tv_sec; - memset(&test_state->clock_delta, 0, sizeof(test_state->clock_delta)); + assert(config->async); + if (test_state->packeted_bio != nullptr && + PacketedBioAdvanceClock(test_state->packeted_bio)) { // The DTLS retransmit logic silently ignores write failures. So the test // may progress, allow writes through synchronously. - if (config->async) { - AsyncBioEnforceWriteQuota(test_state->async_bio, false); - } + AsyncBioEnforceWriteQuota(test_state->async_bio, false); int timeout_ret = DTLSv1_handle_timeout(ssl); - if (config->async) { - AsyncBioEnforceWriteQuota(test_state->async_bio, true); - } + AsyncBioEnforceWriteQuota(test_state->async_bio, true); if (timeout_ret < 0) { fprintf(stderr, "Error retransmitting.\n"); @@ -1336,11 +1319,11 @@ return false; } if (config->is_dtls) { - ScopedBIO packeted = - PacketedBioCreate(&GetTestState(ssl.get())->clock_delta); + ScopedBIO packeted = PacketedBioCreate(!config->async); if (!packeted) { return false; } + GetTestState(ssl.get())->packeted_bio = packeted.get(); BIO_push(packeted.get(), bio.release()); bio = std::move(packeted); }
diff --git a/ssl/test/packeted_bio.cc b/ssl/test/packeted_bio.cc index e831082..01edc26 100644 --- a/ssl/test/packeted_bio.cc +++ b/ssl/test/packeted_bio.cc
@@ -30,6 +30,46 @@ const uint8_t kOpcodeTimeout = 'T'; const uint8_t kOpcodeTimeoutAck = 't'; +struct PacketedBio { + explicit PacketedBio(bool advance_clock_arg) + : advance_clock(advance_clock_arg) { + memset(&timeout, 0, sizeof(timeout)); + memset(&clock, 0, sizeof(clock)); + memset(&read_deadline, 0, sizeof(read_deadline)); + } + + bool HasTimeout() const { + return timeout.tv_sec != 0 || timeout.tv_usec != 0; + } + + bool CanRead() const { + if (read_deadline.tv_sec == 0 && read_deadline.tv_usec == 0) { + return true; + } + + if (clock.tv_sec == read_deadline.tv_sec) { + return clock.tv_usec < read_deadline.tv_usec; + } + return clock.tv_sec < read.deadline.tv_sec; + } + + timeval timeout; + timeval clock; + timeval read_deadline; + bool advance_clock; +}; + +PacketedBio *GetData(BIO *bio) { + if (bio->method != &g_packeted_bio_method) { + return NULL; + } + return (PacketedBio *)bio->ptr; +} + +const PacketedBio *GetData(const BIO *bio) { + return GetData(const_cast<BIO*>(bio)); +} + // ReadAll reads |len| bytes from |bio| into |out|. It returns 1 on success and // 0 or -1 on error. static int ReadAll(BIO *bio, uint8_t *out, size_t len) { @@ -79,90 +119,113 @@ } static int PacketedRead(BIO *bio, char *out, int outl) { + PacketedBio *data = GetData(bio); if (bio->next_bio == NULL) { return 0; } BIO_clear_retry_flags(bio); - // Read the opcode. - uint8_t opcode; - int ret = ReadAll(bio->next_bio, &opcode, sizeof(opcode)); - if (ret <= 0) { - BIO_copy_next_retry(bio); - return ret; - } + for (;;) { + // Check if the read deadline has passed. + if (!data->CanRead()) { + BIO_set_retry_read(bio); + return -1; + } - if (opcode == kOpcodeTimeout) { - // Process the timeout. - uint8_t buf[8]; - ret = ReadAll(bio->next_bio, buf, sizeof(buf)); + // Read the opcode. + uint8_t opcode; + int ret = ReadAll(bio->next_bio, &opcode, sizeof(opcode)); if (ret <= 0) { BIO_copy_next_retry(bio); return ret; } - uint64_t timeout = (static_cast<uint64_t>(buf[0]) << 56) | - (static_cast<uint64_t>(buf[1]) << 48) | - (static_cast<uint64_t>(buf[2]) << 40) | - (static_cast<uint64_t>(buf[3]) << 32) | - (static_cast<uint64_t>(buf[4]) << 24) | - (static_cast<uint64_t>(buf[5]) << 16) | - (static_cast<uint64_t>(buf[6]) << 8) | - static_cast<uint64_t>(buf[7]); - timeout /= 1000; // Convert nanoseconds to microseconds. - timeval *out_timeout = reinterpret_cast<timeval *>(bio->ptr); - assert(out_timeout->tv_usec == 0); - assert(out_timeout->tv_sec == 0); - out_timeout->tv_usec = timeout % 1000000; - out_timeout->tv_sec = timeout / 1000000; - // Send an ACK to the peer. - ret = BIO_write(bio->next_bio, &kOpcodeTimeoutAck, 1); + if (opcode == kOpcodeTimeout) { + // The caller is required to advance any pending timeouts before + // continuing. + if (data->HasTimeout()) { + fprintf(stderr, "Unprocessed timeout!\n"); + return -1; + } + + // Process the timeout. + uint8_t buf[8]; + ret = ReadAll(bio->next_bio, buf, sizeof(buf)); + if (ret <= 0) { + BIO_copy_next_retry(bio); + return ret; + } + uint64_t timeout = (static_cast<uint64_t>(buf[0]) << 56) | + (static_cast<uint64_t>(buf[1]) << 48) | + (static_cast<uint64_t>(buf[2]) << 40) | + (static_cast<uint64_t>(buf[3]) << 32) | + (static_cast<uint64_t>(buf[4]) << 24) | + (static_cast<uint64_t>(buf[5]) << 16) | + (static_cast<uint64_t>(buf[6]) << 8) | + static_cast<uint64_t>(buf[7]); + timeout /= 1000; // Convert nanoseconds to microseconds. + + data->timeout.tv_usec = timeout % 1000000; + data->timeout.tv_sec = timeout / 1000000; + + // Send an ACK to the peer. + ret = BIO_write(bio->next_bio, &kOpcodeTimeoutAck, 1); + if (ret <= 0) { + return ret; + } + assert(ret == 1); + + if (!data->advance_clock) { + // Signal to the caller to retry the read, after advancing the clock. + BIO_set_retry_read(bio); + return -1; + } + + PacketedBioAdvanceClock(bio); + continue; + } + + if (opcode != kOpcodePacket) { + fprintf(stderr, "Unknown opcode, %u\n", opcode); + return -1; + } + + // Read the length prefix. + uint8_t len_bytes[4]; + ret = ReadAll(bio->next_bio, len_bytes, sizeof(len_bytes)); if (ret <= 0) { + BIO_copy_next_retry(bio); return ret; } - assert(ret == 1); - // Signal to the caller to retry the read, after processing the - // new clock. - BIO_set_retry_read(bio); - return -1; - } + uint32_t len = (len_bytes[0] << 24) | (len_bytes[1] << 16) | + (len_bytes[2] << 8) | len_bytes[3]; + uint8_t *buf = (uint8_t *)OPENSSL_malloc(len); + if (buf == NULL) { + return -1; + } + ret = ReadAll(bio->next_bio, buf, len); + if (ret <= 0) { + fprintf(stderr, "Packeted BIO was truncated\n"); + return -1; + } - if (opcode != kOpcodePacket) { - fprintf(stderr, "Unknown opcode, %u\n", opcode); - return -1; + if (outl > (int)len) { + outl = len; + } + memcpy(out, buf, outl); + OPENSSL_free(buf); + return outl; } - - // Read the length prefix. - uint8_t len_bytes[4]; - ret = ReadAll(bio->next_bio, len_bytes, sizeof(len_bytes)); - if (ret <= 0) { - BIO_copy_next_retry(bio); - return ret; - } - - uint32_t len = (len_bytes[0] << 24) | (len_bytes[1] << 16) | - (len_bytes[2] << 8) | len_bytes[3]; - uint8_t *buf = (uint8_t *)OPENSSL_malloc(len); - if (buf == NULL) { - return -1; - } - ret = ReadAll(bio->next_bio, buf, len); - if (ret <= 0) { - fprintf(stderr, "Packeted BIO was truncated\n"); - return -1; - } - - if (outl > (int)len) { - outl = len; - } - memcpy(out, buf, outl); - OPENSSL_free(buf); - return outl; } static long PacketedCtrl(BIO *bio, int cmd, long num, void *ptr) { + if (cmd == BIO_CTRL_DGRAM_SET_NEXT_TIMEOUT) { + memcpy(&GetData(bio)->read_deadline, ptr, sizeof(timeval)); + return 1; + } + if (bio->next_bio == NULL) { return 0; } @@ -182,6 +245,7 @@ return 0; } + delete GetData(bio); bio->init = 0; return 1; } @@ -208,11 +272,33 @@ } // namespace -ScopedBIO PacketedBioCreate(timeval *out_timeout) { +ScopedBIO PacketedBioCreate(bool advance_clock) { ScopedBIO bio(BIO_new(&g_packeted_bio_method)); if (!bio) { return nullptr; } - bio->ptr = out_timeout; + bio->ptr = new PacketedBio(advance_clock); return bio; } + +timeval PacketedBioGetClock(const BIO *bio) { + return GetData(bio)->clock; +} + +bool PacketedBioAdvanceClock(BIO *bio) { + PacketedBio *data = GetData(bio); + if (data == nullptr) { + return false; + } + + if (!data->HasTimeout()) { + return false; + } + + data->clock.tv_usec += data->timeout.tv_usec; + data->clock.tv_sec += data->clock.tv_usec / 1000000; + data->clock.tv_usec %= 1000000; + data->clock.tv_sec += data->timeout.tv_sec; + memset(&data->timeout, 0, sizeof(data->timeout)); + return true; +}
diff --git a/ssl/test/packeted_bio.h b/ssl/test/packeted_bio.h index 75cfa13..f99e544 100644 --- a/ssl/test/packeted_bio.h +++ b/ssl/test/packeted_bio.h
@@ -30,15 +30,22 @@ // PacketedBioCreate creates a filter BIO which implements a reliable in-order -// blocking datagram socket. The resulting BIO, on |BIO_read|, may simulate a -// timeout which sets |*out_timeout| to the timeout and fails the read. -// |*out_timeout| must be zero on entry to |BIO_read|; it is an error to not -// apply the timeout before the next |BIO_read|. +// blocking datagram socket. It internally maintains a clock and honors +// |BIO_CTRL_DGRAM_SET_NEXT_TIMEOUT| based on it. // -// Note: The read timeout simulation is intended to be used with the async BIO -// wrapper. It doesn't simulate BIO_CTRL_DGRAM_SET_NEXT_TIMEOUT, used in DTLS's -// blocking mode. -ScopedBIO PacketedBioCreate(timeval *out_timeout); +// During a |BIO_read|, the peer may signal the filter BIO to simulate a +// timeout. If |advance_clock| is true, it automatically advances the clock and +// continues reading, subject to the read deadline. Otherwise, it fails +// immediately. The caller must then call |PacketedBioAdvanceClock| before +// retrying |BIO_read|. +ScopedBIO PacketedBioCreate(bool advance_clock); + +// PacketedBioGetClock returns the current time for |bio|. +timeval PacketedBioGetClock(const BIO *bio); + +// PacketedBioAdvanceClock advances |bio|'s internal clock and returns true if +// there is a pending timeout. Otherwise, it returns false. +bool PacketedBioAdvanceClock(BIO *bio); #endif // HEADER_PACKETED_BIO
diff --git a/ssl/test/runner/runner.go b/ssl/test/runner/runner.go index 8cc16bd..1b0bf54 100644 --- a/ssl/test/runner/runner.go +++ b/ssl/test/runner/runner.go
@@ -4687,106 +4687,137 @@ } func addDTLSRetransmitTests() { - // Test that this is indeed the timeout schedule. Stress all - // four patterns of handshake. - for i := 1; i < len(timeouts); i++ { - number := strconv.Itoa(i) - testCases = append(testCases, testCase{ + // These tests work by coordinating some behavior on both the shim and + // the runner. + // + // TimeoutSchedule configures the runner to send a series of timeout + // opcodes to the shim (see packetAdaptor) immediately before reading + // each peer handshake flight N. The timeout opcode both simulates a + // timeout in the shim and acts as a synchronization point to help the + // runner bracket each handshake flight. + // + // We assume the shim does not read from the channel eagerly. It must + // first wait until it has sent flight N and is ready to receive + // handshake flight N+1. At this point, it will process the timeout + // opcode. It must then immediately respond with a timeout ACK and act + // as if the shim was idle for the specified amount of time. + // + // The runner then drops all packets received before the ACK and + // continues waiting for flight N. This ordering results in one attempt + // at sending flight N to be dropped. For the test to complete, the + // shim must send flight N again, testing that the shim implements DTLS + // retransmit on a timeout. + + for _, async := range []bool{true, false} { + var tests []testCase + + // Test that this is indeed the timeout schedule. Stress all + // four patterns of handshake. + for i := 1; i < len(timeouts); i++ { + number := strconv.Itoa(i) + tests = append(tests, testCase{ + protocol: dtls, + name: "DTLS-Retransmit-Client-" + number, + config: Config{ + Bugs: ProtocolBugs{ + TimeoutSchedule: timeouts[:i], + }, + }, + resumeSession: true, + }) + tests = append(tests, testCase{ + protocol: dtls, + testType: serverTest, + name: "DTLS-Retransmit-Server-" + number, + config: Config{ + Bugs: ProtocolBugs{ + TimeoutSchedule: timeouts[:i], + }, + }, + resumeSession: true, + }) + } + + // Test that exceeding the timeout schedule hits a read + // timeout. + tests = append(tests, testCase{ protocol: dtls, - name: "DTLS-Retransmit-Client-" + number, + name: "DTLS-Retransmit-Timeout", config: Config{ Bugs: ProtocolBugs{ - TimeoutSchedule: timeouts[:i], + TimeoutSchedule: timeouts, }, }, resumeSession: true, - flags: []string{"-async"}, + shouldFail: true, + expectedError: ":READ_TIMEOUT_EXPIRED:", }) - testCases = append(testCases, testCase{ + + if async { + // Test that timeout handling has a fudge factor, due to API + // problems. + tests = append(tests, testCase{ + protocol: dtls, + name: "DTLS-Retransmit-Fudge", + config: Config{ + Bugs: ProtocolBugs{ + TimeoutSchedule: []time.Duration{ + timeouts[0] - 10*time.Millisecond, + }, + }, + }, + resumeSession: true, + }) + } + + // Test that the final Finished retransmitting isn't + // duplicated if the peer badly fragments everything. + tests = append(tests, testCase{ + testType: serverTest, + protocol: dtls, + name: "DTLS-Retransmit-Fragmented", + config: Config{ + Bugs: ProtocolBugs{ + TimeoutSchedule: []time.Duration{timeouts[0]}, + MaxHandshakeRecordLength: 2, + }, + }, + }) + + // Test the timeout schedule when a shorter initial timeout duration is set. + tests = append(tests, testCase{ + protocol: dtls, + name: "DTLS-Retransmit-Short-Client", + config: Config{ + Bugs: ProtocolBugs{ + TimeoutSchedule: shortTimeouts[:len(shortTimeouts)-1], + }, + }, + resumeSession: true, + flags: []string{"-initial-timeout-duration-ms", "250"}, + }) + tests = append(tests, testCase{ protocol: dtls, testType: serverTest, - name: "DTLS-Retransmit-Server-" + number, + name: "DTLS-Retransmit-Short-Server", config: Config{ Bugs: ProtocolBugs{ - TimeoutSchedule: timeouts[:i], + TimeoutSchedule: shortTimeouts[:len(shortTimeouts)-1], }, }, resumeSession: true, - flags: []string{"-async"}, + flags: []string{"-initial-timeout-duration-ms", "250"}, }) + + for _, test := range tests { + if async { + test.name += "-Async" + test.flags = append(test.flags, "-async") + } + + testCases = append(testCases, test) + } } - - // Test that exceeding the timeout schedule hits a read - // timeout. - testCases = append(testCases, testCase{ - protocol: dtls, - name: "DTLS-Retransmit-Timeout", - config: Config{ - Bugs: ProtocolBugs{ - TimeoutSchedule: timeouts, - }, - }, - resumeSession: true, - flags: []string{"-async"}, - shouldFail: true, - expectedError: ":READ_TIMEOUT_EXPIRED:", - }) - - // Test that timeout handling has a fudge factor, due to API - // problems. - testCases = append(testCases, testCase{ - protocol: dtls, - name: "DTLS-Retransmit-Fudge", - config: Config{ - Bugs: ProtocolBugs{ - TimeoutSchedule: []time.Duration{ - timeouts[0] - 10*time.Millisecond, - }, - }, - }, - resumeSession: true, - flags: []string{"-async"}, - }) - - // Test that the final Finished retransmitting isn't - // duplicated if the peer badly fragments everything. - testCases = append(testCases, testCase{ - testType: serverTest, - protocol: dtls, - name: "DTLS-Retransmit-Fragmented", - config: Config{ - Bugs: ProtocolBugs{ - TimeoutSchedule: []time.Duration{timeouts[0]}, - MaxHandshakeRecordLength: 2, - }, - }, - flags: []string{"-async"}, - }) - - // Test the timeout schedule when a shorter initial timeout duration is set. - testCases = append(testCases, testCase{ - protocol: dtls, - name: "DTLS-Retransmit-Short-Client", - config: Config{ - Bugs: ProtocolBugs{ - TimeoutSchedule: shortTimeouts[:len(shortTimeouts)-1], - }, - }, - resumeSession: true, - flags: []string{"-async", "-initial-timeout-duration-ms", "250"}, - }) - testCases = append(testCases, testCase{ - protocol: dtls, - testType: serverTest, - name: "DTLS-Retransmit-Short-Server", - config: Config{ - Bugs: ProtocolBugs{ - TimeoutSchedule: shortTimeouts[:len(shortTimeouts)-1], - }, - }, - resumeSession: true, - flags: []string{"-async", "-initial-timeout-duration-ms", "250"}, - }) } func addExportKeyingMaterialTests() {