[ParidelPooya]

Fixes #820.

Summary

After a failed SuspendMicrovm call, the worker logs one warning per outcome, with the state as fields. The 10 texts of _failed_call_warning are removed. The behavior is unchanged.

Why

1. _failed_call_warning picked one of 10 texts from the outcome and four state flags.
2. The texts change no behavior.
3. fix(microvm-worker): wait at least 30 s after a suspend refused for now #799 and fix(microvm-worker): state that the refusal ended #817 here, and JS #1049 and #1069, only fixed texts that stated something false.
4. MicroVM worker: the unknown-outcome warning and its refusal are decided in two locked blocks #820 found one more: the text and the 30-second refusal were decided in two locked blocks, so a hook's 30 seconds could end in between.
5. So the message now names only the outcome, and fields carry the state. The fields are read in the locked block that acts on the outcome.

This is item D2 of a review of the MicroVM safeguards. The JS worker makes the same change in aws/aws-durable-execution-sdk-js#1081.

Changes

• Messages:
  • rejected: "could not suspend the idle MicroVM, because the service rejected the call. A missing permission needs lambda:SuspendMicrovm on the MicroVM image in its execution role."
  • refused for now: "could not suspend the idle MicroVM, because the service refused the call for now."
  • unknown: "the suspend call for the idle MicroVM had an unknown outcome."
• Fields, in this order: microvmId, error, outcome, suspendHookArrived, terminating, closed, refusingJobs. refusingJobs is terminating or suspending, the two states in which the job route answers 503.
• The warning is logged outside the lock. The error is described before either locked block, because describe() calls str(), and a client from create_microvms_client controls the exception type.
• For an unknown outcome, the warning is now logged after client.close(), because the block after close() decides the refusal.
• The 30-second wait after a call refused for now is unchanged.
• README item 8 and the listener docstring describe the warning once.

Why not the fix proposed in #820

#820 proposed to start the 30-second refusal before close(). In the #820 sequence, that refuses a job that gets HTTP 202 today. This PR changes no behavior. It reads the fields where the decision is made.

Testing

• Every existing scenario is kept. Each asserts the message, the fields, and one warning per failed call. The status and timing assertions are unchanged.
• A new test replays the MicroVM worker: the unknown-outcome warning and its refusal are decided in two locked blocks #820 sequence. It fails on main and passes here.
• Two new tests, one per outcome, use an error whose __str__() calls listener.close(), or sends a suspend hook. Both fail on the first version of this PR (c2464b1), and pass now.
• hatch run dev-microvm-worker:cov: 457 tests pass. worker.py stays at 100 %. Typecheck and hatch fmt --check pass. A stress run with -n 8 passed 3 times.

By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.

[yaythomas]

Both calls to _failed_call_log() now run while self._lock is held. _failed_call_log() calls describe(error), and describe() calls str(error). A client supplied through create_microvms_client controls that exception type. So its __str__() runs while the listener holds a non-reentrant lock. A slow implementation blocks every hook and job request. An implementation that calls back into the listener can deadlock.

I reproduced the deadlock with an exception whose __str__() calls listener.close(). The same probe completes on the base revision. safe_logger() cannot prevent this because describe() runs before the logger call.

Can this compute describe(error) before entering either locked block, then pass the resulting object to _failed_call_log()?

[ParidelPooya]

Thanks, confirmed and fixed in 7704e9f. The except block now calls describe(error) before either locked block, and _failed_call_log() receives the described object. New tests raise an error whose __str__() calls listener.close() or sends a suspend hook, for each outcome. They fail on c2464b1 and pass now. Two older calls log under the lock on main (_start_idle_time and _start_grace, when a timer cannot start). Their error comes from threading.Timer.start(), not from the caller, so I left them for a separate issue.

[yaythomas]