From 0736180849d947650da794119bfb220238dd0570 Mon Sep 17 00:00:00 2001 From: elhoim Date: Thu, 3 Sep 2026 08:06:11 +0000 Subject: [PATCH] fix: wait for the publish worker in test_search_publish_timestamp The test asserts that a search for publish_timestamp='5s' returns exactly one event immediately after creating it. Since 2.5.40 MISP sets the publish timestamp in a background worker rather than during add_event, so this only passed because the three invalid-query searches in between happened to take longer than the worker's tick. That makes the test sensitive to unrelated server-side performance. It fails reproducibly against a MISP branch that removes a bcrypt verification from every authenticated REST request: the same 85-test suite drops from 190-217s to 146s, the three queries return before the worker has published, and the search correctly matches nothing - "AssertionError: 0 != 1". Wait for publication instead of relying on incidental latency: - add _wait_until_published(), which polls until the event reports published with a non-zero publish_timestamp, and fails with a clear message on timeout rather than letting a later assertion fail obscurely. It accepts publish_timestamp as either the int 0 add_event returns or the datetime pythonify produces once the worker has run. - wait for the first event before creating the second, so the two publish timestamps are genuinely separated. The previous sleep separated only the creation times, which is not what the interval assertion compares. - wait for the second event before the 5-second window assertion. - drop the fixed 10s sleep that preceded the re-fetch. It slowed the suite down and still raised AttributeError on int.timestamp() whenever the worker was slower than the guess. - assert the two publish timestamps are more than 5s apart, so a violation reports the real gap instead of an opaque count mismatch. The test is now driven by the worker's actual progress, so it neither races a faster server nor pays a fixed delay on a slower one. Co-Authored-By: Claude Opus 5 (1M context) --- tests/testlive_comprehensive.py | 59 +++++++++++++++++++++++++++------ 1 file changed, 48 insertions(+), 11 deletions(-) diff --git a/tests/testlive_comprehensive.py b/tests/testlive_comprehensive.py index be06e1918..91238c310 100644 --- a/tests/testlive_comprehensive.py +++ b/tests/testlive_comprehensive.py @@ -141,6 +141,29 @@ def create_simple_event(self, force_timestamps: bool=False) -> MISPEvent: mispevent.add_attribute('text', str(uuid4())) return mispevent + def _wait_until_published(self, event: MISPEvent, timeout: int=30) -> MISPEvent: + """Block until the background worker has actually published `event`. + + Since MISP 2.5.40 publishing is handed to a background job, so + add_event() returns before publish_timestamp is set. Any assertion on a + publication window has to wait for the worker rather than assume the + calls made in between took long enough. + """ + deadline = time.time() + timeout + while time.time() < deadline: + fetched = self.pub_misp_connector.get_event(event, pythonify=True) + if not isinstance(fetched, MISPEvent): + self.fail(f'could not re-fetch event while waiting for publication: {fetched}') + # publish_timestamp is a plain int (0) until the worker sets it, + # and a datetime once pythonify can parse it. + published_at = fetched.publish_timestamp + if isinstance(published_at, datetime): + published_at = published_at.timestamp() + if fetched.published and int(published_at or 0): + return fetched + time.sleep(0.5) + self.fail(f'event {event.id} was not published within {timeout}s') + def environment(self) -> tuple[MISPEvent, MISPEvent, MISPEvent]: first_event = MISPEvent() first_event.info = 'First event - org only - low - completed' @@ -671,6 +694,13 @@ def test_search_publish_timestamp(self) -> None: second.publish() try: first = self.pub_misp_connector.add_event(first, pythonify=True) + # The interval assertion at the end needs the two events' publish + # timestamps to be at least 5s apart. Publishing is done by a + # background worker, so wait until the first event is really + # published before creating the second: sleeping a fixed amount + # only separates the *creation* times, which is not what is + # compared below. + first = self._wait_until_published(first) time.sleep(10) second = self.pub_misp_connector.add_event(second, pythonify=True) # Test invalid query @@ -680,21 +710,28 @@ def test_search_publish_timestamp(self) -> None: self.assertEqual(events, []) events = self.pub_misp_connector.search(publish_timestamp='aaad', pythonify=True) self.assertEqual(events, []) + # Wait for the background publish worker before asserting on a + # 5-second publication window. Without this the assertion races the + # worker: it only passed because the three invalid queries above + # happened to take long enough, so any speed-up on the server (or a + # faster runner) makes the search run first and match nothing. + second = self._wait_until_published(second) # Test - last 4 min events = self.pub_misp_connector.search(publish_timestamp='5s', pythonify=True) - self.assertEqual(len(events), 1) + self.assertEqual(len(events), 1, events) self.assertEqual(events[0].id, second.id) - # we need to sleep here as per 2.5.40 we've moved the publish timestamp setting to the background process instead of front loading it. - # The default tick rate of the background worker is 5s so 10 seconds should be safe-ish. (assuming no other fuck-ups) - time.sleep(10) - - # The add_event response no longer carries the publish_timestamp (it is now set by the background - # publish job, not synchronously), so the events fetched above still hold publish_timestamp == 0, - # which pythonify leaves as a plain int rather than a datetime. Re-fetch them now that the worker - # has published so publish_timestamp is populated as a datetime for the .timestamp() calls below. - first = self.pub_misp_connector.get_event(first, pythonify=True) - second = self.pub_misp_connector.get_event(second, pythonify=True) + # Both events have already been waited on above, so their + # publish_timestamp is a datetime rather than the int 0 that + # add_event returns since 2.5.40. That replaces a fixed 10s sleep, + # which both slowed the suite down and still raised AttributeError + # whenever the worker happened to be slower than the guess. + + # The interval assertion below only distinguishes the two events if + # their publish timestamps are more than 5s apart. Check it here so + # a violation reports the actual gap instead of an opaque count. + gap = second.publish_timestamp.timestamp() - first.publish_timestamp.timestamp() + self.assertGreater(gap, 5, f'publish timestamps only {gap}s apart') # Test 5 sec before timestamp of 2nd event events = self.pub_misp_connector.search(publish_timestamp=(second.publish_timestamp.timestamp()), pythonify=True)