Fix IP address being labelled "bad" for too long (#718)

**Issue:**

A server went offline for a while to do some updates. But when it came back online later, it wasn't getting any traffic. The expectation is that traffic to this server would eventually resume.

**Diagnosis:**

The default host resolver has a "bad" list of addresses (connect attempt failed). The idea is: don't use these addresses unless there are NO known good addresses.

Due to quirks of the code, addresses in the "bad' list would not be removed when their TTL expired. Maybe this was an accident? Maybe the author just wanted to avoid some looping?

In any case, this could result in the address being labeled "bad" FOREVER. Even if the server and DNS did the right thing: not reporting the address while the server was offline but reporting it again later when everything was good, the aws_host_resolver cache would still have the address in its "bad" list.

The only way to get off the bad list would be if ALL good addresses failed, and the resolver was forced to pull from the bad list.

But we need to handle a reasonable world, where an address might randomly go bad for a while and get better later.

**Description of changes:**

- Remove addresses in the bad list when their TTL expires
  - TTL is currently [30sec by default](https://github.com/awslabs/aws-c-io/blob/9c7c52cb0d61b6644e6fb1973fcd680d62435ac7/source/host_resolver.c#L23-L24), [5min for aws-c-s3](https://github.com/awslabs/aws-c-s3/blob/169842b7e2f81d71d0719d4a77f9c3e186512f99/source/s3_client.c#L81-L82) (these may change in the future)
- If an address is in the "bad" list, but DNS is still reporting it, don't update its TTL.

So now, if there's a failed connection, the address will remain on the "bad" list until its TTL expires, even if that address appears in future DNS queries. Then, the address will be removed from all caches. If a future DNS query returns that address again, it will go into the "good" list.

Author: graebm

source/host_resolver.c

@@ -520,16 +520,22 @@ static inline void process_records(
     AWS_LOGF_TRACE(AWS_LS_IO_DNS, "static: remaining record count for host %d", (int)record_count);
 
     /* if we don't have any known good addresses, take the least recently used, but not expired address with a history
-     * of spotty behavior and upgrade it for reuse. If it's expired, leave it and let the resolve fail. Better to fail
-     * than accidentally give a kids' app an IP address to somebody's adult website when the IP address gets rebound to
-     * a different endpoint. The moral of the story here is to not disable SSL verification! */
-    if (!record_count) {
-        size_t failed_count = aws_cache_get_element_count(failed_records);
-        for (size_t index = 0; index < failed_count; ++index) {
-            struct aws_host_address_cache_entry *lru_element_entry = aws_lru_cache_use_lru_element(failed_records);
-            if (timestamp >= lru_element_entry->address.expiry) {
-                continue;
-            }
+     * of spotty behavior and upgrade it for reuse. */
+    bool should_promote = (record_count == 0);
+    size_t failed_count = aws_cache_get_element_count(failed_records);
+    for (size_t index = 0; index < failed_count; ++index) {
+        struct aws_host_address_cache_entry *lru_element_entry = aws_lru_cache_use_lru_element(failed_records);
+
+        /* remove expired entries */
+        if (timestamp >= lru_element_entry->address.expiry) {
+            AWS_LOGF_DEBUG(
+                AWS_LS_IO_DNS,
+                "static: purging expired bad record %s for %s",
+                lru_element_entry->address.address->bytes,
+                lru_element_entry->address.host->bytes);
+            aws_cache_remove(failed_records, lru_element_entry->address.address);
+
+        } else if (should_promote) {
 
             struct aws_host_address_cache_entry *to_add =
                 aws_mem_calloc(host_entry->allocator, 1, sizeof(struct aws_host_address_cache_entry));
@@ -558,7 +564,7 @@ static inline void process_records(
             aws_cache_remove(failed_records, lru_element_entry->address.address);
 
             /* we only want to promote one per process run.*/
-            break;
+            should_promote = false;
         }
     }
 }
@@ -703,24 +709,33 @@ static int resolver_record_connection_failure(
  * A bunch of convenience functions for the host resolver background thread function
  */
 
-static struct aws_host_address_cache_entry *s_find_cached_address_entry_aux(
+struct aws_host_address_cache_entry_lookup {
+    struct aws_host_address_cache_entry *entry; /* if lookup succeeds, this is non-NULL */
+    bool is_fallback;
+};
+
+static struct aws_host_address_cache_entry_lookup s_find_cached_address_entry_aux(
     struct aws_cache *primary_records,
     struct aws_cache *fallback_records,
     const struct aws_string *address) {
 
     struct aws_host_address_cache_entry *found = NULL;
+    bool is_fallback = false;
     aws_cache_find(primary_records, address, (void **)&found);
     if (found == NULL) {
         aws_cache_find(fallback_records, address, (void **)&found);
+        if (found != NULL) {
+            is_fallback = true;
+        }
     }
 
-    return found;
+    return (struct aws_host_address_cache_entry_lookup){.entry = found, .is_fallback = is_fallback};
 }
 
 /*
  * Looks in both the good and failed connection record sets for a given host record
  */
-static struct aws_host_address_cache_entry *s_find_cached_address_entry(
+static struct aws_host_address_cache_entry_lookup s_find_cached_address_entry(
     struct host_entry *entry,
     const struct aws_string *address,
     enum aws_address_record_type record_type) {
@@ -733,7 +748,7 @@ static struct aws_host_address_cache_entry *s_find_cached_address_entry(
             return s_find_cached_address_entry_aux(entry->a_records, entry->failed_connection_a_records, address);
 
         default:
-            return NULL;
+            return (struct aws_host_address_cache_entry_lookup){.entry = NULL};
     }
 }
 
@@ -779,19 +794,30 @@ static void s_update_address_cache(
         struct aws_host_address *fresh_resolved_address = NULL;
         aws_array_list_get_at_ptr(address_list, (void **)&fresh_resolved_address, i);
 
-        struct aws_host_address_cache_entry *address_to_cache_entry = s_find_cached_address_entry(
+        struct aws_host_address_cache_entry_lookup cache_lookup = s_find_cached_address_entry(
             host_entry, fresh_resolved_address->address, fresh_resolved_address->record_type);
 
-        if (address_to_cache_entry) {
-            address_to_cache_entry->address.expiry = new_expiration;
-            AWS_LOGF_TRACE(
-                AWS_LS_IO_DNS,
-                "static: updating expiry for %s for host %s to %llu",
-                address_to_cache_entry->address.address->bytes,
-                host_entry->host_name->bytes,
-                (unsigned long long)new_expiration);
+        if (cache_lookup.entry) {
+            struct aws_host_address_cache_entry *address_to_cache_entry = cache_lookup.entry;
+            if (cache_lookup.is_fallback) {
+                AWS_LOGF_TRACE(
+                    AWS_LS_IO_DNS,
+                    "static: NOT updating expiry for %s for host %s because it's in bad list."
+                    " Keeping old expiry of %" PRIu64,
+                    aws_string_c_str(address_to_cache_entry->address.address),
+                    aws_string_c_str(host_entry->host_name),
+                    address_to_cache_entry->address.expiry);
+            } else {
+                address_to_cache_entry->address.expiry = new_expiration;
+                AWS_LOGF_TRACE(
+                    AWS_LS_IO_DNS,
+                    "static: updating expiry for %s for host %s to %" PRIu64,
+                    aws_string_c_str(address_to_cache_entry->address.address),
+                    aws_string_c_str(host_entry->host_name),
+                    new_expiration);
+            }
         } else {
-            address_to_cache_entry =
+            struct aws_host_address_cache_entry *address_to_cache_entry =
                 aws_mem_calloc(host_entry->allocator, 1, sizeof(struct aws_host_address_cache_entry));
 
             aws_host_address_move(fresh_resolved_address, &address_to_cache_entry->address);

tests/CMakeLists.txt

@@ -113,6 +113,7 @@ add_net_test_case(test_default_with_ipv4_only_lookup)
 add_test_case(test_resolver_ttls)
 add_test_case(test_resolver_connect_failure_recording)
 add_test_case(test_resolver_ttl_refreshes_on_resolve)
+add_test_case(test_resolver_bad_list_expires_eventually)
 add_test_case(test_resolver_low_frequency_starvation)
 
 add_test_case(test_pem_single_cert_parse)

tests/default_host_resolver_test.c

@@ -1060,6 +1060,170 @@ static int s_test_resolver_ttl_refreshes_on_resolve_fn(struct aws_allocator *all
 
 AWS_TEST_CASE(test_resolver_ttl_refreshes_on_resolve, s_test_resolver_ttl_refreshes_on_resolve_fn)
 
+/**
+ * Test that a failed address isn't stuck on the bad list for eternity.
+ *
+ * This is a regression test for a real world use case:
+ * A server went offline for a while to do some updates.
+ * But when it came back online later, it wasn't getting any traffic.
+ * The expectation is that traffic to this server would eventually resume.
+ *
+ * The cause was: the default host resolver didn't purge addresses
+ * from the bad list after their TTL expired. Once an address got on the bad list,
+ * it was nearly impossible to ever get off it.
+ */
+static int s_test_resolver_bad_list_expires_eventually_fn(struct aws_allocator *allocator, void *ctx) {
+    (void)ctx;
+
+    aws_io_library_init(allocator);
+
+    struct aws_event_loop_group_options elg_options = {
+        .loop_count = 1,
+    };
+    struct aws_event_loop_group *el_group = aws_event_loop_group_new(allocator, &elg_options);
+
+    struct aws_host_resolver_default_options resolver_options = {
+        .el_group = el_group,
+        .max_entries = 10,
+    };
+    struct aws_host_resolver *resolver = aws_host_resolver_new_default(allocator, &resolver_options);
+
+    const struct aws_string *host_name = aws_string_new_from_c_str(allocator, "host_address");
+
+    /*
+     * Set up mock DNS with 2 addresses.
+     * We'll tell the host resolver that a connection to addr1 failed.
+     * (don't report both as failed, or bad addresses will move back to the
+     * good list through mechanisms we're testing elsewhere)
+     * The mock DNS will continually report those same 2 addresses.
+     * Assert that, at some point in the future, the host resolver yields addr1 again.
+     */
+
+    const struct aws_string *addr1_ipv4 = aws_string_new_from_c_str(allocator, "address1ipv4");
+    const struct aws_string *addr2_ipv4 = aws_string_new_from_c_str(allocator, "address2ipv4");
+
+    struct mock_dns_resolver mock_resolver;
+    ASSERT_SUCCESS(mock_dns_resolver_init(&mock_resolver, 1000, allocator));
+
+    struct aws_host_resolution_config config = {
+        /* short TTL so bad entries expire and get removed without this test taking too long */
+        .max_ttl = 2 /*sec*/,
+        .impl = mock_dns_resolve,
+        .impl_data = &mock_resolver,
+    };
+
+    struct aws_host_address host_address_1_ipv4 = {
+        .address = addr1_ipv4,
+        .allocator = allocator,
+        .host = aws_string_new_from_c_str(allocator, "host_address"),
+        .record_type = AWS_ADDRESS_RECORD_TYPE_A,
+    };
+
+    struct aws_host_address host_address_2_ipv4 = {
+        .address = addr2_ipv4,
+        .allocator = allocator,
+        .host = aws_string_new_from_c_str(allocator, "host_address"),
+        .record_type = AWS_ADDRESS_RECORD_TYPE_A,
+    };
+
+    struct aws_array_list address_list_1;
+    ASSERT_SUCCESS(aws_array_list_init_dynamic(&address_list_1, allocator, 2, sizeof(struct aws_host_address)));
+    ASSERT_SUCCESS(aws_array_list_push_back(&address_list_1, &host_address_1_ipv4));
+    ASSERT_SUCCESS(aws_array_list_push_back(&address_list_1, &host_address_2_ipv4));
+
+    ASSERT_SUCCESS(mock_dns_resolver_append_address_list(&mock_resolver, &address_list_1));
+
+    struct aws_mutex mutex = AWS_MUTEX_INIT;
+    struct default_host_callback_data callback_data = {
+        .condition_variable = AWS_CONDITION_VARIABLE_INIT,
+        .mutex = &mutex,
+    };
+
+    /*
+     * Do first lookup, we expect to get addr1.
+     */
+
+    ASSERT_SUCCESS(aws_host_resolver_resolve_host(
+        resolver, host_name, s_default_host_resolved_test_callback, &config, &callback_data));
+
+    /* BEGIN CRITICAL SECTION */
+    ASSERT_SUCCESS(aws_mutex_lock(&mutex));
+    aws_condition_variable_wait_pred(
+        &callback_data.condition_variable, &mutex, s_default_host_resolved_predicate, &callback_data);
+
+    ASSERT_INT_EQUALS(0, aws_string_compare(addr1_ipv4, callback_data.a_address.address));
+
+    aws_host_address_clean_up(&callback_data.a_address);
+    callback_data.invoked = false;
+    aws_mutex_unlock(&mutex);
+    /* END CRITICAL SECTION */
+
+    /*
+     * Report addr1 as failed.
+     * Then do repeated lookups in a loop.
+     * We expect to see addr2 again and again, until we eventually see addr1.
+     */
+
+    ASSERT_SUCCESS(aws_host_resolver_record_connection_failure(resolver, &host_address_1_ipv4));
+
+    uint64_t num_times_received_addr1 = 0;
+    uint64_t num_times_received_addr2 = 0;
+
+    uint64_t start_timestamp_ns = 0;
+    aws_high_res_clock_get_ticks(&start_timestamp_ns);
+    while (num_times_received_addr1 == 0) {
+
+        /* Check for timeout */
+        uint64_t current_timestamp_ns = 0;
+        aws_high_res_clock_get_ticks(&current_timestamp_ns);
+
+        uint64_t looping_secs = aws_timestamp_convert(
+            current_timestamp_ns - start_timestamp_ns, AWS_TIMESTAMP_NANOS, AWS_TIMESTAMP_SECS, NULL);
+        ASSERT_TRUE(looping_secs < 10, "Timed out waiting for addr1 to get off bad list");
+
+        /* Sleep a moment, to keep logs at reasonable size */
+        uint64_t sleep_ns = aws_timestamp_convert(100, AWS_TIMESTAMP_MILLIS, AWS_TIMESTAMP_NANOS, NULL);
+        aws_thread_current_sleep(sleep_ns);
+
+        /* Do lookup */
+        ASSERT_SUCCESS(aws_host_resolver_resolve_host(
+            resolver, host_name, s_default_host_resolved_test_callback, &config, &callback_data));
+
+        /* BEGIN CRITICAL SECTION */
+        ASSERT_SUCCESS(aws_mutex_lock(&mutex));
+        aws_condition_variable_wait_pred(
+            &callback_data.condition_variable, &mutex, s_default_host_resolved_predicate, &callback_data);
+
+        if (aws_string_compare(addr1_ipv4, callback_data.a_address.address) == 0) {
+            ++num_times_received_addr1;
+        } else if (aws_string_compare(addr2_ipv4, callback_data.a_address.address) == 0) {
+            ++num_times_received_addr2;
+        } else {
+            ASSERT_TRUE(false, "Received unexpected address");
+        }
+
+        aws_host_address_clean_up(&callback_data.a_address);
+        callback_data.invoked = false;
+        aws_mutex_unlock(&mutex);
+        /* END CRITICAL SECTION */
+    }
+
+    ASSERT_TRUE(num_times_received_addr2 > 10, "Expected to see a lot of addr2 while addr1 was on bad list");
+
+    /* clean up */
+    aws_host_resolver_release(resolver);
+    aws_string_destroy((void *)host_name);
+    aws_event_loop_group_release(el_group);
+
+    aws_io_library_clean_up();
+
+    mock_dns_resolver_clean_up(&mock_resolver);
+
+    return 0;
+}
+
+AWS_TEST_CASE(test_resolver_bad_list_expires_eventually, s_test_resolver_bad_list_expires_eventually_fn)
+
 static int s_test_resolver_ipv4_address_lookup_fn(struct aws_allocator *allocator, void *ctx) {
     (void)ctx;