Skip to content

Commit fefdb59

Browse files
e2e: replace timing waits with bounded synchronization (#1253)
## Stack - Stacked on #1252; review this PR after or against that branch. ## What changed - replace one-second connection polling and unbounded event/future waits with bounded condition-based synchronization - remove method subscription sleeps because receive-handler setters synchronously wait for feature subscription - signal Event Hub readiness after the first active receive cycle instead of sleeping three seconds - start each helper from its construction timestamp so later partitions retain new events without replaying prior test traffic - filter raw-string telemetry waits by expected payload so delayed unrelated events cannot satisfy them - guarantee service-helper shutdown if readiness fails before fixture yield - run the Event Hub receiver on a daemon-backed future so its 30-second shutdown timeout cannot be bypassed - bound twin matching/retry loops with absolute deadlines - remove import-time iptables mutation; existing per-test setup restores network state - co-locate focused wait-helper and Event Hub lifecycle tests under the IoT Hub E2E suite ## Validation - Python 3.12 unit suite: 5437 passed, 6 skipped - E2E infrastructure tests: 13 passed - Black and Ruff passed - all 132 IoT Hub E2E tests collected without cloud access - previous natural build, Python E2E, DPS E2E, and Horton E2E gates passed --------- Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
1 parent 4196881 commit fefdb59

23 files changed

Lines changed: 490 additions & 151 deletions

‎dev_utils/dev_utils/service_helper.py‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -29,6 +29,9 @@ async def _run_in_executor(self, func, *args):
2929
def set_identity(self, device_id, module_id):
3030
return self._inner_object.set_identity(device_id, module_id)
3131

32+
async def wait_until_ready(self, timeout):
33+
return await self._run_in_executor(self._inner_object.wait_until_ready, timeout)
34+
3235
async def set_desired_properties(self, desired_props):
3336
return await self._run_in_executor(self._inner_object.set_desired_properties, desired_props)
3437

@@ -54,11 +57,12 @@ async def send_c2d(
5457
):
5558
return await self._run_in_executor(self._inner_object.send_c2d, payload, properties)
5659

57-
async def wait_for_eventhub_arrival(self, message_id, timeout=60):
60+
async def wait_for_eventhub_arrival(self, message_id, timeout=60, event_filter=None):
5861
return await self._run_in_executor(
5962
self._inner_object.wait_for_eventhub_arrival,
6063
message_id,
6164
timeout,
65+
event_filter,
6266
)
6367

6468
async def get_next_reported_patch_arrival(self, block=True, timeout=240):

‎dev_utils/dev_utils/service_helper_sync.py‎

Lines changed: 52 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -7,7 +7,8 @@
77
import copy
88
import time
99
import uuid
10-
from concurrent.futures import ThreadPoolExecutor
10+
import datetime
11+
import concurrent.futures
1112
from azure.iot.hub import IoTHubRegistryManager
1213
from azure.iot.hub.protocol.models import Twin, TwinProperties, CloudToDeviceMethod
1314
from azure.eventhub import EventHubConsumerClient
@@ -78,8 +79,6 @@ def __init__(
7879
eventhub_connection_string,
7980
eventhub_consumer_group,
8081
):
81-
self._executor = ThreadPoolExecutor()
82-
8382
self._registry_manager = IoTHubRegistryManager(iothub_connection_string)
8483

8584
logger.info(
@@ -91,13 +90,32 @@ def __init__(
9190
self._eventhub_consumer_client = EventHubConsumerClient.from_connection_string(
9291
eventhub_connection_string, consumer_group=eventhub_consumer_group
9392
)
94-
95-
self._eventhub_future = self._executor.submit(self._eventhub_thread)
9693
self.device_id = None
9794
self.module_id = None
9895
self.incoming_patch_queue = queue.Queue()
9996
self.cv = threading.Condition()
10097
self.incoming_eventhub_events = {}
98+
self._eventhub_start_position = datetime.datetime.now(datetime.timezone.utc)
99+
self._eventhub_ready = threading.Event()
100+
self._eventhub_future = self._start_eventhub_thread()
101+
self._eventhub_future.add_done_callback(lambda _: self._eventhub_ready.set())
102+
103+
def _start_eventhub_thread(self):
104+
future = concurrent.futures.Future()
105+
106+
def run():
107+
if not future.set_running_or_notify_cancel():
108+
return
109+
try:
110+
result = self._eventhub_thread()
111+
except BaseException as e:
112+
future.set_exception(e)
113+
else:
114+
future.set_result(result)
115+
116+
self._eventhub_worker = threading.Thread(target=run, daemon=True)
117+
self._eventhub_worker.start()
118+
return future
101119

102120
def set_identity(self, device_id, module_id):
103121
if device_id != self.device_id or module_id != self.module_id:
@@ -113,6 +131,15 @@ def set_identity(self, device_id, module_id):
113131
)
114132
self.incoming_eventhub_events = {}
115133

134+
def wait_until_ready(self, timeout):
135+
if not self._eventhub_ready.wait(timeout=timeout):
136+
raise TimeoutError(
137+
"EventHub consumer did not initialize within {} seconds".format(timeout)
138+
)
139+
if self._eventhub_future.done():
140+
self._eventhub_future.result()
141+
raise RuntimeError("EventHub consumer exited before initializing")
142+
116143
def set_desired_properties(self, desired_props):
117144
if self.module_id:
118145
self._registry_manager.update_module_twin(
@@ -155,15 +182,26 @@ def send_c2d(self, payload, properties):
155182
raise TypeError("sending C2D to modules is not supported")
156183
self._registry_manager.send_c2d_message(self.device_id, payload, properties)
157184

158-
def wait_for_eventhub_arrival(self, message_id, timeout=900):
185+
def wait_for_eventhub_arrival(self, message_id, timeout=900, event_filter=None):
159186
def get_event(inner_message_id):
160187
with self.cv:
161188
arrivals = self.incoming_eventhub_events
162189

163190
# if message_id is not set, return any message
164191
if not inner_message_id and len(arrivals):
165-
id = list(arrivals.keys())[0]
166-
logger.info("wait_for_eventhub_arrival(None) returning msgid={}".format(id))
192+
if event_filter:
193+
id = next(
194+
(
195+
event_id
196+
for event_id, event in arrivals.items()
197+
if event_filter(event)
198+
),
199+
None,
200+
)
201+
else:
202+
id = next(iter(arrivals))
203+
if id:
204+
logger.info("wait_for_eventhub_arrival(None) returning msgid={}".format(id))
167205
else:
168206
id = inner_message_id
169207

@@ -203,14 +241,13 @@ def shutdown(self):
203241

204242
if self._eventhub_future:
205243
try:
206-
# Ensure the EventHub receive loop exits before tearing down the executor
244+
# Ensure the EventHub receive loop exits after closing the consumer
207245
self._eventhub_future.result(timeout=30)
246+
except concurrent.futures.TimeoutError:
247+
logger.warning("_eventhub_thread did not exit within 30 seconds")
208248
except Exception:
209249
logger.warning("_eventhub_thread did not exit cleanly", exc_info=True)
210250

211-
if self._executor:
212-
self._executor.shutdown(wait=True)
213-
214251
def _convert_incoming_event(self, event):
215252
try:
216253
event_body = event.body_as_json()
@@ -255,6 +292,8 @@ def on_partition_close(partition_context, reason):
255292

256293
def on_event_batch(partition_context, events):
257294
try:
295+
# A completed receive confirms that the Event Hub consumer is active
296+
self._eventhub_ready.set()
258297
for event in events:
259298
device_id = get_device_id_from_event(event)
260299
module_id = get_module_id_from_event(event)
@@ -294,6 +333,7 @@ def on_event_batch(partition_context, events):
294333
logger.info("Starting EventHub receive")
295334
self._eventhub_consumer_client.receive_batch(
296335
max_wait_time=2,
336+
starting_position=self._eventhub_start_position,
297337
on_event_batch=on_event_batch,
298338
on_error=on_error,
299339
on_partition_initialize=on_partition_initialize,

‎tests/e2e/iothub_e2e/aio/conftest.py‎

Lines changed: 12 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@
77
import datetime
88
import json
99
import retry_async
10+
import const
1011
from utils import create_client_object
1112
from azure.iot.device.iothub.aio import IoTHubDeviceClient, IoTHubModuleClient
1213

@@ -103,14 +104,16 @@ async def service_helper(executor):
103104
eventhub_consumer_group=test_env.EVENTHUB_CONSUMER_GROUP,
104105
executor=executor,
105106
)
106-
yield service_helper
107-
108-
logger.info("----------------------------")
109-
logger.info("shutting down service_helper")
110-
logger.info("----------------------------")
107+
try:
108+
await service_helper.wait_until_ready(timeout=const.E2E_TIMEOUT)
109+
yield service_helper
110+
finally:
111+
logger.info("----------------------------")
112+
logger.info("shutting down service_helper")
113+
logger.info("----------------------------")
111114

112-
await service_helper.shutdown()
115+
await service_helper.shutdown()
113116

114-
logger.info("---------------------------------")
115-
logger.info("service helper shut down complete")
116-
logger.info("---------------------------------")
117+
logger.info("---------------------------------")
118+
logger.info("service helper shut down complete")
119+
logger.info("---------------------------------")

‎tests/e2e/iothub_e2e/aio/test_c2d.py‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,7 @@
66
import logging
77
import json
88
from dev_utils import get_random_dict
9+
import const
910

1011
logger = logging.getLogger(__name__)
1112
logger.setLevel(level=logging.INFO)
@@ -38,7 +39,7 @@ async def handle_on_message_received(message):
3839

3940
await service_helper.send_c2d(message, {})
4041

41-
await asyncio.wait_for(received.wait(), 60)
42+
await asyncio.wait_for(received.wait(), timeout=const.E2E_TIMEOUT)
4243
assert received.is_set()
4344

4445
assert received_message.data.decode("utf-8") == message

‎tests/e2e/iothub_e2e/aio/test_connect_disconnect.py‎

Lines changed: 16 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,8 @@
55
import pytest
66
import logging
77
import parametrize
8+
import const
9+
import wait_helpers
810

911
logger = logging.getLogger(__name__)
1012
logger.setLevel(level=logging.INFO)
@@ -78,7 +80,7 @@ async def handle_on_connection_state_change():
7880
await client.disconnect()
7981

8082
# wait for handle_on_connection_state_change to reconnect
81-
await reconnected_event.wait()
83+
await asyncio.wait_for(reconnected_event.wait(), timeout=const.E2E_TIMEOUT)
8284

8385
logger.info(
8486
"reconnect_event.wait() returned. client.connected={}".format(client.connected)
@@ -160,7 +162,7 @@ async def handle_on_connection_state_change():
160162
await client.connect()
161163

162164
# and wait for us to disconnect
163-
await disconnected_event.wait()
165+
await asyncio.wait_for(disconnected_event.wait(), timeout=const.E2E_TIMEOUT)
164166
assert not client.connected
165167

166168
# sleep a while and make sure that we're still disconnected.
@@ -198,14 +200,16 @@ async def test_disconnect_on_drop_outgoing(self, client, dropper, leak_tracker):
198200
assert client.connected
199201
dropper.drop_outgoing()
200202

201-
while client.connected:
202-
await asyncio.sleep(1)
203+
await wait_helpers.async_wait_for_condition(
204+
lambda: not client.connected, timeout=const.E2E_TIMEOUT
205+
)
203206

204207
# we've passed the test. Now wait to reconnect before we check for leaks. Otherwise we
205208
# have a pending ConnectOperation floating around and this would get tagged as a leak.
206209
dropper.restore_all()
207-
while not client.connected:
208-
await asyncio.sleep(1)
210+
await wait_helpers.async_wait_for_condition(
211+
lambda: client.connected, timeout=const.E2E_TIMEOUT
212+
)
209213

210214
leak_tracker.check_for_leaks()
211215

@@ -221,13 +225,15 @@ async def test_disconnect_on_reject_outgoing(self, client, dropper, leak_tracker
221225
assert client.connected
222226
dropper.reject_outgoing()
223227

224-
while client.connected:
225-
await asyncio.sleep(1)
228+
await wait_helpers.async_wait_for_condition(
229+
lambda: not client.connected, timeout=const.E2E_TIMEOUT
230+
)
226231

227232
# we've passed the test. Now wait to reconnect before we check for leaks. Otherwise we
228233
# have a pending ConnectOperation floating around and this would get tagged as a leak.
229234
dropper.restore_all()
230-
while not client.connected:
231-
await asyncio.sleep(1)
235+
await wait_helpers.async_wait_for_condition(
236+
lambda: client.connected, timeout=const.E2E_TIMEOUT
237+
)
232238

233239
leak_tracker.check_for_leaks()

‎tests/e2e/iothub_e2e/aio/test_methods.py‎

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@
33
# license information.
44
import pytest
55
import logging
6-
import asyncio
6+
77
import parametrize
88
from dev_utils import get_random_dict
99
from azure.iot.device.iothub import MethodResponse
@@ -62,7 +62,6 @@ async def handle_on_method_request_received(request):
6262
)
6363

6464
client.on_method_request_received = handle_on_method_request_received
65-
await asyncio.sleep(1) # wait for subscribe, etc, to complete
6665

6766
# invoke the method call
6867
method_response = await service_helper.invoke_method(method_name, request_payload)

‎tests/e2e/iothub_e2e/aio/test_sas_renewal.py‎

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@
77
import logging
88
import test_config
99
import parametrize
10+
import const
1011

1112
logger = logging.getLogger(__name__)
1213
logger.setLevel(level=logging.INFO)
@@ -50,7 +51,7 @@ async def handle_on_connection_state_change():
5051
# setting on_connection_state_change seems to have the side effect of
5152
# calling handle_on_connection_state_change once with the initial value.
5253
# Wait for one disconnect/reconnect cycle so we can get past it.
53-
await connected_event.wait()
54+
await asyncio.wait_for(connected_event.wait(), timeout=const.E2E_TIMEOUT)
5455

5556
# OK, we're ready to test. wait for the renewal
5657
token_before_connect = str(token_object)
@@ -59,9 +60,9 @@ async def handle_on_connection_state_change():
5960
connected_event.clear()
6061

6162
logger.info("Waiting for client to disconnect")
62-
await disconnected_event.wait()
63+
await asyncio.wait_for(disconnected_event.wait(), timeout=const.E2E_TIMEOUT)
6364
logger.info("Waiting for client to reconnect")
64-
await connected_event.wait()
65+
await asyncio.wait_for(connected_event.wait(), timeout=const.E2E_TIMEOUT)
6566
logger.info("Client reconnected")
6667

6768
# Finally verify that our token changed.

0 commit comments

Comments
 (0)