fix(microvm-worker): state that the refusal ended

packages/aws-durable-execution-sdk-python-microvm-worker/README.md

@@ -111,7 +111,7 @@ A session's run hook payload can set `autoSuspendIdleSeconds`. The session sets
 5. The refusal ends when the `resume` lifecycle hook arrives, or 30 seconds after the call returned, if no hook arrives. The idle time then starts again. At most one call runs at a time. A `resume` hook that arrives during the call ends the refusal at once, and the next idle time starts when the call ends. So enable the `resume` hook in the image. Without it, the first job after a resume can wait a little over 30 seconds: the 30 seconds, plus up to 4 seconds until the durable function's next delivery attempt. A test measured 32 seconds.
 6. A call that the service rejected on its first attempt, such as `AccessDeniedException` for a missing permission, is logged as a warning, and the MicroVM keeps running. Missing credentials count as a rejection. A later call in the same MicroVM most likely finds no credentials either. The worker accepts jobs again at once and does not retry the call. The next job that ends starts the idle time again. The exception is a `resume` hook that arrived during the call. The idle time then starts when the call ends. So the worker retries the call one idle time after the call ends, if no job runs and no `suspend` hook refusal is in effect when the call ends. A second exception is a `suspend` hook that arrived during the call and whose refusal is still in effect when the call ends. The MicroVM is then suspending anyway. So the rejection does not end the hook's refusal. That refusal ends on the `resume` hook, or 30 seconds after the last `suspend` hook. The idle time then starts again.
 7. A call that the service refused for now on its first attempt is logged as a warning too, and the worker accepts jobs again at once. This covers expired credentials and a signature error, with or without a clock offset, whatever the HTTP status. The service answers these before it acts. botocore retries none of these errors, so they reach the worker on the first attempt. The idle time then starts again, so the worker tries the call again. That idle time lasts at least 30 seconds, also when `autoSuspendIdleSeconds` is shorter. The same error can repeat on every call, for example with a wrong secret key or an expired session token from environment variables. So while no job ends and no lifecycle hook arrives, the worker makes at most one call per 30 seconds, and logs one warning per call. A job that ends after the refusal, or a `resume` hook after it, starts the normal idle time instead. A `resume` hook or a job that ends during the call does not shorten the idle time after the refusal, because the refused outcome arrives after it. A `suspend` hook whose refusal is still in effect when the call ends is the exception, as in item 6. Its refusal stays, and the idle time starts when it ends. The default client retries a throttle, so a throttle from it usually ends as an unknown outcome, as in item 8. A throttle counts as refused for now only from a client that does not retry it, such as a client from `create_microvms_client` with one attempt. The JavaScript worker classifies these errors the same way. Its default client retries a clock-skew error. So there, a clock-skew error usually ends as an unknown outcome.
-8. A call whose outcome is unknown is handled like a successful call, because the service may have suspended the MicroVM anyway. This covers a timeout, a conflict, a server error, and a dropped connection. An error after botocore retried an earlier attempt also counts as unknown, because the earlier attempt may have suspended the MicroVM. The default client uses botocore's standard retry mode with 3 attempts, and that mode retries a throttle. So a throttle usually ends here. The refusal continues until the `resume` hook or the 30-second limit. The idle time then starts again, so the worker tries the call again.
+8. A call whose outcome is unknown is handled like a successful call, because the service may have suspended the MicroVM anyway. This covers a timeout, a conflict, a server error, and a dropped connection. An error after botocore retried an earlier attempt also counts as unknown, because the earlier attempt may have suspended the MicroVM. The default client uses botocore's standard retry mode with 3 attempts, and that mode retries a throttle. So a throttle usually ends here. The refusal continues until the `resume` hook or the 30-second limit. The idle time then starts again, so the worker tries the call again. A `resume` hook during the call, or the end of a `suspend` hook's 30 seconds during the call, has already ended the refusal. The worker then accepts jobs at once, and tries the call again one idle time after the call and every job end.
 
 `worker.close()` stops the idle time. A closed worker never suspends its MicroVM again. A refusal that is already running still ends on the `resume` hook or after 30 seconds.
 

packages/aws-durable-execution-sdk-python-microvm-worker/src/aws_durable_execution_sdk_python_microvm_worker/worker.py

@@ -213,8 +213,16 @@ def _failed_call_warning(
        idle time after the call and every job end.
     7. A refusal for now otherwise: the next idle time lasts at least 30
        seconds, unless a job or a resume hook starts the idle time again.
-    8. An unknown outcome otherwise: the refusal continues until the resume
-       hook, or for 30 seconds.
+    8. An unknown outcome after the refusal of jobs ended during the call:
+       a resume hook ended it, or the 30-second limit of a suspend hook's
+       refusal. The listener starts no new refusal after an unknown outcome
+       when ``suspending`` is false. So it accepts jobs. It calls again one
+       idle time after the call and every job end.
+    9. The same after ``close()`` during the call: the listener accepts
+       jobs. ``_start_idle_time`` starts no idle time. So the listener never
+       calls again.
+    10. An unknown outcome otherwise: the refusal continues until the resume
+        hook, or for 30 seconds.
     """
     if outcome is SuspendOutcome.UNKNOWN:
         if terminating:
@@ -223,6 +231,22 @@ def _failed_call_warning(
                 "The MicroVM is terminating, so the worker refuses jobs and "
                 "does not try the call again."
             )
+        if not suspending:
+            if closed:
+                return (
+                    "the suspend call for the idle MicroVM had an unknown "
+                    "outcome. The refusal of jobs already ended during the "
+                    "call, on a resume hook or after 30 seconds. So the worker "
+                    "accepts jobs. The worker is closed, so it does not try "
+                    "the call again."
+                )
+            return (
+                "the suspend call for the idle MicroVM had an unknown outcome. "
+                "The refusal of jobs already ended during the call, on a "
+                "resume hook or after 30 seconds. So the worker accepts jobs. "
+                "It tries the call again one idle time after the call and "
+                "every job end."
+            )
         return (
             "the suspend call for the idle MicroVM had an unknown outcome. The "
             "worker refuses jobs until the MicroVM resumes, or for 30 seconds."
@@ -432,6 +456,10 @@ class MicrovmWorkerListener:
        successful call. The service may have suspended the MicroVM anyway.
        No attempt of the call starts after 10 seconds. An attempt already in
        flight runs until it ends, and the refusal lasts at least until then.
+       A `resume` hook during the call, or the end of a `suspend` hook's 30
+       seconds during the call, has already ended the refusal. The worker
+       then accepts jobs at once, and tries the call again one idle time
+       after the call and every job end.
 
     When the image enables the ``suspend`` and ``terminate`` hooks, the
     listener acts on them:
@@ -1592,9 +1620,12 @@ def _call_suspend(
             deferred = []
             with self._lock:
                 # The warning depends on this state. The block reads it
-                # before it changes it. So the text matches the decision
-                # below, whatever another thread does after the lock is
-                # released.
+                # before it changes it. For a rejection and a refusal for
+                # now, this block also makes the decision. So for these two
+                # outcomes, the text matches the decision, whatever another
+                # thread does after the lock is released. For an unknown
+                # outcome, the block at the end of this method decides
+                # whether the 30-second refusal starts. See issue #820.
                 hook_arrived = self._suspend_hooks != hooks_before
                 terminating = self._terminating
                 closed = self._closed

packages/aws-durable-execution-sdk-python-microvm-worker/tests/lifecycle_hooks_test.py

@@ -95,6 +95,18 @@
     "MicroVM is terminating, so the worker refuses jobs and does not try the "
     "call again."
 )
+UNKNOWN_ENDED = (
+    "the suspend call for the idle MicroVM had an unknown outcome. The refusal "
+    "of jobs already ended during the call, on a resume hook or after 30 "
+    "seconds. So the worker accepts jobs. It tries the call again one idle "
+    "time after the call and every job end."
+)
+UNKNOWN_ENDED_CLOSED = (
+    "the suspend call for the idle MicroVM had an unknown outcome. The refusal "
+    "of jobs already ended during the call, on a resume hook or after 30 "
+    "seconds. So the worker accepts jobs. The worker is closed, so it does not "
+    "try the call again."
+)
 
 LAMBDA_HEADERS = {"Host": "localhost:8080"}
 FORWARDED_HEADERS = {
@@ -1240,8 +1252,8 @@ def end_failed_call(h: Harness) -> None:
 
 @pytest.mark.parametrize(
     "hooks",
-    [["terminate"], ["suspend", "terminate"]],
-    ids=["terminate", "suspend-then-terminate"],
+    [["terminate"], ["suspend", "terminate"], ["resume", "terminate"]],
+    ids=["terminate", "suspend-then-terminate", "resume-then-terminate"],
 )
 @pytest.mark.parametrize(
     ("failure", "text"),
@@ -1403,6 +1415,131 @@ def test_says_the_microvm_keeps_running_after_a_rejection_when_the_hook_refusal_
     assert logger.messages("warning") == [REJECTED]
 
 
+@pytest.mark.parametrize("then", ["job", "no-job"])
+@pytest.mark.parametrize(
+    ("during", "failure"),
+    [
+        # The own call suspended the MicroVM, and its answer was lost across
+        # the freeze. The resume hook arrives, and the connection then drops.
+        ("resume", ConnectionResetError("reset")),
+        ("suspend-resume", suspend_error("InternalServerException", 500, 2)),
+        # botocore cannot cancel an attempt in flight. A client from
+        # create_microvms_client with 60-second timeouts can outlast the
+        # hook's 30 seconds.
+        ("suspend-grace", ConnectionResetError("reset")),
+    ],
+    ids=["resume", "suspend-resume", "suspend-grace"],
+)
+def test_says_the_refusal_ended_after_an_unknown_outcome_when_it_ended_during_the_call(
+    start: Any, logger: Any, during: str, failure: BaseException, then: str
+) -> None:
+    # The refusal of jobs ends during the call: on a resume hook, or 30
+    # seconds after a suspend hook. An unknown outcome then starts no new
+    # refusal. So the worker accepts jobs. It calls again one idle time after
+    # the call and every job end.
+    h = start()
+    hold_failed_call(h, failure)
+    if during == "resume":
+        assert h.hook("resume") == 200
+    elif during == "suspend-resume":
+        assert h.hook("suspend") == 200
+        assert h.hook("resume") == 200
+    else:
+        assert h.hook("suspend") == 200
+        h.advance(GRACE - 0.001)
+        assert h.job("cb-0") == 503
+        h.advance(0.001)
+        # The call still runs. So no second call started.
+        assert h.microvms.suspended == ["mvm-1"]
+        assert logger.messages("warning") == []
+    end_failed_call(h)
+
+    assert logger.messages("warning") == [UNKNOWN_ENDED]
+    if then == "job":
+        assert h.job("cb-1") == 202
+        assert eventually(lambda: h.started("cb-1"))
+        h.advance(GRACE)
+        assert h.microvms.suspended == ["mvm-1"]
+        h.finish_job("cb-1")
+    h.advance(IDLE - 0.001)
+    assert h.microvms.suspended == ["mvm-1"]
+    h.advance(0.001)
+    assert h.microvms.suspended == ["mvm-1", "mvm-1"]
+    assert logger.messages("warning") == [UNKNOWN_ENDED]
+
+
+def test_calls_again_one_idle_time_after_the_last_job_after_an_unknown_outcome(
+    start: Any, logger: Any
+) -> None:
+    # A resume hook ends the refusal during the call. A job then starts
+    # during the call. A running job cancels the idle time. So the next call
+    # comes one idle time after the last job ends, not after the call.
+    h = start()
+    hold_failed_call(h, ConnectionResetError("reset"))
+    assert h.hook("resume") == 200
+    assert h.job("cb-1") == 202
+    assert eventually(lambda: h.started("cb-1"))
+    end_failed_call(h)
+
+    assert logger.messages("warning") == [UNKNOWN_ENDED]
+    assert h.job("cb-2") == 202
+    h.advance(IDLE * 3)
+    assert h.microvms.suspended == ["mvm-1"]
+    h.finish_job("cb-1")
+    h.advance(IDLE)
+    assert h.microvms.suspended == ["mvm-1"]
+    h.finish_job("cb-2")
+    h.advance(IDLE - 0.001)
+    assert h.microvms.suspended == ["mvm-1"]
+    h.advance(0.001)
+    assert h.microvms.suspended == ["mvm-1", "mvm-1"]
+    assert logger.messages("warning") == [UNKNOWN_ENDED]
+
+
+def test_says_that_no_call_follows_an_unknown_outcome_after_close_and_a_resume_hook(
+    start: Any, logger: Any
+) -> None:
+    # A closed listener starts no idle time. So the resume hook ends the
+    # refusal, and no call follows.
+    h = start()
+    hold_failed_call(h, suspend_error("InternalServerException", 500, 2))
+    h.listener.close()
+    assert h.hook("resume") == 200
+    end_failed_call(h)
+
+    assert logger.messages("warning") == [UNKNOWN_ENDED_CLOSED]
+    assert h.job("cb-1") == 202
+    h.finish_job("cb-1")
+    h.advance(IDLE + GRACE * 4)
+    assert h.microvms.suspended == ["mvm-1"]
+
+
+@pytest.mark.parametrize("during", ["no-hook", "suspend", "close"])
+def test_keeps_the_refusal_text_after_an_unknown_outcome_while_the_refusal_lasts(
+    start: Any, logger: Any, during: str
+) -> None:
+    # The refusal is still in effect when the call ends. So the worker
+    # refuses jobs for 30 seconds after the call, or until the resume hook.
+    h = start()
+    hold_failed_call(h, suspend_error("InternalServerException", 500, 2))
+    if during == "suspend":
+        assert h.hook("suspend") == 200
+    elif during == "close":
+        h.listener.close()
+    end_failed_call(h)
+
+    assert logger.messages("warning") == [UNKNOWN]
+    assert h.job("cb-1") == 503
+    h.advance(GRACE - 0.001)
+    assert h.job("cb-2") == 503
+    h.advance(0.001)
+    assert h.job("cb-3") == 202
+    h.finish_job("cb-3")
+    h.advance(IDLE)
+    expected = ["mvm-1"] if during == "close" else ["mvm-1", "mvm-1"]
+    assert h.microvms.suspended == expected
+
+
 @pytest.mark.parametrize(
     ("idle", "waited"), [(1.0, GRACE), (45.0, 45.0)], ids=["idle-1s", "idle-45s"]
 )