Work on ec2_vpc_subnet related test flake (#1848) (#1870)

[PR #1848/c510f26e backport][stable-6] Work on ec2_vpc_subnet related test flake

This is a backport of PR #1848 as merged into main (c510f26).
SUMMARY
As with all things AWS there are no guarantees how fast things will be created.  We currently have a hard coded delay of ~10 seconds to wait for the subnet to be created, while advertising a default timeout of 300s.  If this 10s is exceeded, then we throw a 'NoneType' object is not subscriptable error (because we didn't check that the subnet was actually returned)
This moves a for-loop over to a waiter.  The "waiter_handler" logic already makes sure we have a total waiting time matching the limits set, even if we wait for multiple things to happen)
ISSUE TYPE

Bugfix Pull Request

COMPONENT NAME
ec2_vpc_subnet
ADDITIONAL INFORMATION
2023-11-13 07:08:17.514752 | controller | TASK [ec2_ami_tpm : create a subnet to use for creating an ec2 instance] *******
2023-11-13 07:08:17.514756 | controller | task path: /home/zuul-worker/.ansible/collections/ansible_collections/amazon/aws/tests/integration/targets/ec2_ami_tpm/tasks/main.yml:31
2023-11-13 07:08:29.688395 | controller | Using module file /home/zuul-worker/.ansible/collections/ansible_collections/amazon/aws/plugins/modules/ec2_vpc_subnet.py
2023-11-13 07:08:29.688433 | controller | Pipelining is enabled.
2023-11-13 07:08:29.688440 | controller | <testhost> ESTABLISH LOCAL CONNECTION FOR USER: zuul-worker
2023-11-13 07:08:29.688481 | controller | <testhost> EXEC /bin/sh -c 'ANSIBLE_DEBUG_BOTOCORE_LOGS=True /home/zuul-worker/venv/bin/python && sleep 0'
2023-11-13 07:08:29.688488 | controller | The full traceback is:
2023-11-13 07:08:29.688494 | controller | Traceback (most recent call last):
2023-11-13 07:08:29.688501 | controller |   File "<stdin>", line 121, in <module>
2023-11-13 07:08:29.688508 | controller |   File "<stdin>", line 113, in _ansiballz_main
2023-11-13 07:08:29.688514 | controller |   File "<stdin>", line 61, in invoke_module
2023-11-13 07:08:29.688520 | controller |   File "<frozen runpy>", line 226, in run_module
2023-11-13 07:08:29.688526 | controller |   File "<frozen runpy>", line 98, in _run_module_code
2023-11-13 07:08:29.688533 | controller |   File "<frozen runpy>", line 88, in _run_code
2023-11-13 07:08:29.688539 | controller |   File "/tmp/ansible_ec2_vpc_subnet_payload_g63mopop/ansible_ec2_vpc_subnet_payload.zip/ansible_collections/amazon/aws/plugins/modules/ec2_vpc_subnet.py", line 584, in <module>
2023-11-13 07:08:29.688547 | controller |   File "/tmp/ansible_ec2_vpc_subnet_payload_g63mopop/ansible_ec2_vpc_subnet_payload.zip/ansible_collections/amazon/aws/plugins/modules/ec2_vpc_subnet.py", line 574, in main
2023-11-13 07:08:29.688553 | controller |   File "/tmp/ansible_ec2_vpc_subnet_payload_g63mopop/ansible_ec2_vpc_subnet_payload.zip/ansible_collections/amazon/aws/plugins/modules/ec2_vpc_subnet.py", line 491, in ensure_subnet_present
2023-11-13 07:08:29.688560 | controller |   File "/tmp/ansible_ec2_vpc_subnet_payload_g63mopop/ansible_ec2_vpc_subnet_payload.zip/ansible_collections/amazon/aws/plugins/modules/ec2_vpc_subnet.py", line 501, in ensure_final_subnet
2023-11-13 07:08:29.688567 | controller | TypeError: 'NoneType' object is not subscriptable
2023-11-13 07:08:29.688572 | controller | fatal: [testhost]: FAILED! => {
2023-11-13 07:08:29.688579 | controller |     "changed": false,
2023-11-13 07:08:29.688587 | controller |     "module_stderr": "Traceback (most recent call last):\n  File \"<stdin>\", line 121, in <module>\n  File \"<stdin>\", line 113, in _ansiballz_main\n  File \"<stdin>\", line 61, in invoke_module\n  File \"<frozen runpy>\", line 226, in run_module\n  File \"<frozen runpy>\", line 98, in _run_module_code\n  File \"<frozen runpy>\", line 88, in _run_code\n  File \"/tmp/ansible_ec2_vpc_subnet_payload_g63mopop/ansible_ec2_vpc_subnet_payload.zip/ansible_collections/amazon/aws/plugins/modules/ec2_vpc_subnet.py\", line 584, in <module>\n  File \"/tmp/ansible_ec2_vpc_subnet_payload_g63mopop/ansible_ec2_vpc_subnet_payload.zip/ansible_collections/amazon/aws/plugins/modules/ec2_vpc_subnet.py\", line 574, in main\n  File \"/tmp/ansible_ec2_vpc_subnet_payload_g63mopop/ansible_ec2_vpc_subnet_payload.zip/ansible_collections/amazon/aws/plugins/modules/ec2_vpc_subnet.py\", line 491, in ensure_subnet_present\n  File \"/tmp/ansible_ec2_vpc_subnet_payload_g63mopop/ansible_ec2_vpc_subnet_payload.zip/ansible_collections/amazon/aws/plugins/modules/ec2_vpc_subnet.py\", line 501, in ensure_final_subnet\nTypeError: 'NoneType' object is not subscriptable\n",
2023-11-13 07:08:29.688599 | controller |     "module_stdout": "",
2023-11-13 07:08:29.688607 | controller |     "msg": "MODULE FAILURE\nSee stdout/stderr for the exact error",
2023-11-13 07:08:29.688614 | controller |     "rc": 1
2023-11-13 07:08:29.688620 | controller | }

See also:
https://1c9f147019056ec08967-4a68a93a4e95f691374839dd8e3d025a.ssl.cf2.rackcdn.com/1846/7ae4218aaee617a59d13e46e8d0120456210b0fd/check/integration-amazon.aws-5/3714ce7/job-output.txt

Reviewed-by: Mark Chappell

changelogs/fragments/1848-ec2_vpc_subnet-wait-creation.yml

@@ -0,0 +1,4 @@
+bugfixes:
+- ec2_vpc_subnet - cleanly handle failure when subnet isn't created in time (https://github.com/ansible-collections/amazon.aws/pull/1848).
+minor_changes:
+- ec2_vpc_subnet - use ``wait_timeout`` to also control maximum time to wait for initial creation of subnets (https://github.com/ansible-collections/amazon.aws/pull/1848).

plugins/modules/ec2_vpc_subnet.py

@@ -420,8 +420,12 @@ def ensure_ipv6_cidr_block(conn, module, subnet, ipv6_cidr, check_mode, start_ti
     return changed
 
 
+def _matching_subnet_filters(vpc_id, cidr):
+    return ansible_dict_to_boto3_filter_list({"vpc-id": vpc_id, "cidr-block": cidr})
+
+
 def get_matching_subnet(conn, module, vpc_id, cidr):
-    filters = ansible_dict_to_boto3_filter_list({"vpc-id": vpc_id, "cidr-block": cidr})
+    filters = _matching_subnet_filters(vpc_id, cidr)
     try:
         _subnets = conn.describe_subnets(aws_retry=True, Filters=filters)
         subnets = get_subnet_info(_subnets)
@@ -481,11 +485,11 @@ def ensure_subnet_present(conn, module):
 
     subnet = get_matching_subnet(conn, module, module.params["vpc_id"], module.params["cidr"])
     if not module.check_mode and module.params["wait"]:
-        for _rewait in range(0, 5):
-            if subnet:
-                break
-            time.sleep(2)
-            subnet = get_matching_subnet(conn, module, module.params["vpc_id"], module.params["cidr"])
+        subnet_filter = _matching_subnet_filters(module.params["vpc_id"], module.params["cidr"])
+        handle_waiter(conn, module, "subnet_exists", {"Filters": subnet_filter}, start_time)
+        subnet = get_matching_subnet(conn, module, module.params["vpc_id"], module.params["cidr"])
+        if not subnet:
+            module.fail_json("Failed to describe newly created subnet")
         # GET calls are not monotonic for map_public_ip_on_launch and assign_ipv6_address_on_creation
         # so we only wait for those if necessary just before returning the subnet
         subnet = ensure_final_subnet(conn, module, subnet, start_time)