Revert the AMI bump and instrument the cloud suites instead

The Ubuntu 24.04 default measured worse, not better. Against the 4.3.1
release run, over the same 123 tests: test_create_and_list_image went
26.2 -> 33.8 min and test_instance_start_stop_methods 20.3 -> 29.1 min.
Plausibly the larger image costs more to snapshot while CB_VM_TYPE_AWS
stays on a pre-Nitro type, so there is no launch saving to offset it.

That run did exercise the new image, incidentally: the cloud workflow
triggers on pull_request_target, so its definition comes from the base
branch and the CB_IMAGE_AWS wiring was inert, but tests/ is checked out
from the PR head, so the default applied.

Restore the previous image and record on it what was tried and measured,
so the next person does not repeat it - including that the constraint the
old comment cited (moto needing the id to match custom_amis.json) has not
existed since 3fbcba2.

The deeper problem is that end-to-end timings cannot settle this: the same
test has measured 26.2, 60.6 and 33.8 min across three runs, so a single
run cannot resolve a 30% difference in either direction. Add tracing that
times the individual waits instead. CB_TEST_TRACE=1 records every wait_for
poll and every botocore retry, per xdist worker, and tox prints the files
afterwards; --durations=25 replaces inferring per-test times from gaps
between result lines in the CI log, which cannot tell a slow test from a
worker waiting for work.

Records go to files rather than stderr because pytest captures stderr at
fd level and discards it for passing tests, and the filter keeps only the
poll lines and genuine retries - cloudbridge at DEBUG is ~10x the volume
and botocore logs a line per request either way.

CB_TEST_TRACE is set for the AWS suite in tox.ini rather than the workflow
env, since pull_request_target means a PR cannot change the workflow. That
setenv line is diagnostic and marked for removal.

tests/conftest.py

@@ -0,0 +1,103 @@
+"""
+Opt-in tracing for the cloud integration suites.
+
+The AWS suite's wall time is dominated by one or two tests, and end-to-end
+timings have proved too noisy to attribute - test_create_and_list_image alone
+has measured 26.2, 60.6 and 33.8 minutes across three runs of the same 123
+tests. Answering *where* that time goes needs the individual waits timed
+rather than the test as a whole.
+
+Set CB_TEST_TRACE=1 to capture, per xdist worker:
+
+* every ``wait_for`` poll, which brackets each wait - the span from a wait's
+  first poll to its last is the wait itself, and the gap between consecutive
+  polls shows whether the state call is slow (the interval is 1s for real
+  providers, so a larger gap is the API, not the sleep);
+* botocore retries, which is how throttling appears client-side. Those
+  loggers stay silent unless a request is actually retried, so anything they
+  emit is signal.
+
+Records go to cb-trace-<worker>.log rather than stderr because pytest
+captures stderr at file-descriptor level, and captured output is discarded
+for passing tests - which these are. tox prints the files once the run
+finishes.
+
+Deliberately opt-in: at a 1s poll interval a 30 minute wait is ~1800 lines
+for a single waiting resource.
+"""
+import logging
+import os
+
+TRACE_FILE_PREFIX = 'cb-trace-'
+
+
+def _tracing_requested():
+    return (os.environ.get('CB_TEST_TRACE') or '').lower() in (
+        '1', 'true', 'yes')
+
+
+def _trace_path():
+    # Each xdist worker needs its own file; they run in one directory and
+    # would otherwise interleave mid-line.
+    worker = os.environ.get('PYTEST_XDIST_WORKER', 'main')
+    return '{0}{1}.log'.format(TRACE_FILE_PREFIX, worker)
+
+
+class _WaitAndRetryOnly(logging.Filter):
+    """
+    Keep the poll lines, the test markers and the retries; drop the rest.
+
+    cloudbridge at DEBUG is far too chatty to keep wholesale - most of the
+    volume is per-request logging from the provider helpers, which says
+    nothing about where a wait went.
+    """
+
+    def filter(self, record):
+        message = record.getMessage()
+        if record.name.startswith('botocore'):
+            # botocore logs a line per request either way; only the ones
+            # where it actually backed off say anything about throttling.
+            return not message.startswith('Not retrying')
+        return message.startswith('=== ') or 'Waiting another' in message
+
+
+def pytest_configure(config):
+    if not _tracing_requested():
+        return
+
+    handler = logging.FileHandler(_trace_path(), mode='w')
+    handler.setFormatter(logging.Formatter(
+        '%(asctime)s %(name)s %(message)s'))
+    handler.addFilter(_WaitAndRetryOnly())
+
+    # wait_for logs one line per poll at DEBUG, naming the object and the
+    # state it is waiting on. Scope the level to that module rather than the
+    # cloudbridge tree: raising the whole tree to DEBUG would have every
+    # provider request build a log record that the filter then discards, and
+    # those records still propagate to pytest's own capture handler, which
+    # holds them for the duration of the test.
+    waits = logging.getLogger('cloudbridge.base.resources')
+    waits.addHandler(handler)
+    waits.setLevel(logging.DEBUG)
+
+    # Quiet unless a request is actually retried, which is how throttling
+    # shows up client-side. Enabling botocore wholesale would log every
+    # request and response.
+    for name in ('botocore.retries', 'botocore.retryhandler'):
+        target = logging.getLogger(name)
+        target.addHandler(handler)
+        target.setLevel(logging.DEBUG)
+
+
+def pytest_runtest_logstart(nodeid, location):
+    # Stamps the trace with test boundaries, so a span of polls can be
+    # attributed to the test that caused it.
+    if _tracing_requested():
+        logging.getLogger('cloudbridge.base.resources').debug(
+            '=== START %s', nodeid)
+
+
+def pytest_runtest_logfinish(nodeid, location):
+    if _tracing_requested():
+        logging.getLogger('cloudbridge.base.resources').debug(
+            '=== END %s', nodeid)

tests/helpers/__init__.py

@@ -95,21 +95,29 @@ def env_or(varname, default_value):
 
 TEST_DATA_CONFIG = {
     "AWSCloudProvider": {
-        # Ubuntu 24.04 LTS, us-east-1, amd64, gp3 (Canonical, 20260714). AMI
-        # ids are per-region, so a run anywhere but us-east-1 has to set
-        # CB_IMAGE_AWS - as does anyone wanting a different distribution.
+        # Canonical's Ubuntu 16.04, built 2017 - a Xen-era HVM image, and an
+        # AMI id is per-region, so anything but us-east-1 must set
+        # CB_IMAGE_AWS. Kept deliberately, not by inertia:
         #
-        # Being Nitro-era matters: the AWS suite's wall time is dominated by
-        # launching an instance, snapshotting it into an AMI, launching a
-        # second instance from that AMI and stop/start cycling, and all of
-        # those are markedly slower on the Xen-era image this replaced
-        # (Ubuntu 16.04, built 2017). Pair it with a Nitro instance type -
-        # t3.micro or larger - via CB_VM_TYPE_AWS; on a t2.* the gain is
-        # mostly lost, and 24.04 is a tight fit in t2.nano's 512 MB.
+        # The comment that used to sit here said moto needed this value to
+        # match an entry in tests/fixtures/custom_amis.json. That has not been
+        # true since 3fbcba2 removed MOTO_AMIS_PATH from tox.ini - nothing
+        # loads that fixture, and moto does not validate instance-launch AMI
+        # ids, so the mock provider is indifferent to this value.
         #
-        # moto does not validate instance-launch AMI ids, so the mock
-        # provider is indifferent to this value.
-        "image": env_or('CB_IMAGE_AWS', 'ami-052355af2a014bd2c'),
+        # With that constraint gone the obvious move was a current image, on
+        # the theory that the suite's wall time - dominated by launching an
+        # instance, snapshotting it into an AMI, launching a second instance
+        # from it, and stop/start cycling - is paying a Xen-era penalty.
+        # Measured against Ubuntu 24.04 (ami-052355af2a014bd2c), it got
+        # worse: test_create_and_list_image went 26.2 -> 33.8 min and
+        # test_instance_start_stop_methods 20.3 -> 29.1 min. Plausibly the
+        # larger image costs more to snapshot while CB_VM_TYPE_AWS stays on a
+        # pre-Nitro type, so there is no launch saving to offset it. Worth
+        # revisiting only alongside a Nitro instance type, and note the same
+        # test has measured 26.2, 60.6 and 33.8 min across three runs, so a
+        # single run cannot resolve a difference this size either way.
+        "image": env_or('CB_IMAGE_AWS', 'ami-aa2ea6d0'),
         "vm_type": env_or('CB_VM_TYPE_AWS', 't2.nano'),
         "placement": env_or('CB_PLACEMENT_AWS', 'us-east-1a'),
         "placement_cfg_key": "aws_zone_name"

tox.ini

@@ -10,7 +10,15 @@ envlist = py3{.10,.13}-{aws,azure,gcp,openstack,mock},lint,mypy
 
 [testenv]
 commands = # see pyproject.toml for coverage options; setup.cfg for flake8
-           coverage run --source=cloudbridge -m pytest -v {posargs:-n 5 tests/}
+           # --durations reports the slowest tests with their setup/teardown.
+           # The cloud suites' wall time is set by one or two long tests, and
+           # this is the authoritative record of which - the alternative is
+           # inferring it from gaps between result lines in the CI log, which
+           # cannot separate a slow test from a worker waiting for work.
+           coverage run --source=cloudbridge -m pytest -v --durations=25 {posargs:-n 5 tests/}
+           # Emit any CB_TEST_TRACE output (see tests/conftest.py). A no-op
+           # when tracing is off, which is the default.
+           python -c "import glob,sys;[sys.stdout.write(open(f).read()) for f in sorted(glob.glob('cb-trace-*.log'))]"
            # Combine parallel-mode data files and emit Cobertura XML for upload
            # by coverallsapp/github-action in CI. Locally this produces
            # coverage.xml in the project root, which IDEs can also consume.
@@ -20,6 +28,12 @@ setenv =
     # Fix for moto import issue: https://github.com/travis-ci/travis-ci/issues/7940
     BOTO_CONFIG=/dev/null
     aws: CB_TEST_PROVIDER=aws
+    # DIAGNOSTIC - REMOVE BEFORE MERGING. Turns on the wait/retry tracing
+    # described in tests/conftest.py for the AWS suite. It lives here rather
+    # than in the workflow env because the cloud workflow triggers on
+    # pull_request_target, so its definition comes from the base branch and a
+    # PR cannot change it; tox.ini is checked out from the PR head and can.
+    aws: CB_TEST_TRACE=1
     azure: CB_TEST_PROVIDER=azure
     gcp: CB_TEST_PROVIDER=gcp
     openstack: CB_TEST_PROVIDER=openstack
@@ -28,6 +42,10 @@ setenv =
     COVERAGE_FILE=.coverage.{envname}
 passenv =
     PYTHONUNBUFFERED
+    # Set to 1 to log every wait_for poll and every botocore retry, for
+    # working out where a slow cloud suite is actually spending its time.
+    # See tests/conftest.py; verbose by design, so opt-in.
+    CB_TEST_TRACE
     aws: CB_IMAGE_AWS
     aws: CB_VM_TYPE_AWS
     aws: CB_PLACEMENT_AWS