Allow ignoring shelved periods when billing VMs

When a VM is in a shelved state, we don't want to bill users.
`get_runtime_during()` has been refactored and corresponding test cases added.
Time spent in various VM states is now calculated by simulating the VM
as a finite state machine. Each state is represented as a `State` object
instance, which is entered upon certain trigger events (i.e the `Running`
state is entered on `unshelve`, `start`, or `create`).

We assume all state transitions are valid, and will not include
any validations for unusual event sequences (i.e `stopped` -> `unshelve`)

When in the `Error` state, the VM is not billable. New test cases,
mostly written by Kristi, have been added to reflect this desired behavior.
This behavior has been clarified in discussions and led to the discovery
of a bug regarding billing in the `Error` state [1].

[1] #114 (comment)

Author: QuanMPhm

src/openstack_billing_db/model.py

@@ -10,6 +10,21 @@
 logger = logging.getLogger(__name__)
 
 
+@dataclass
+class State:
+    name: str
+    triggers: list[str]
+
+    time_in: int = 0
+    _last_entered: datetime.datetime = None
+
+    def enter(self, time: datetime.datetime):
+        self._last_entered = time
+
+    def exit(self, time: datetime.datetime):
+        self.time_in += (time - self._last_entered).total_seconds()
+
+
 @dataclass_json()
 @dataclass()
 class Flavor(object):
@@ -73,61 +88,71 @@ def _clamp_time(time, min_time, max_time):
         return time
 
     def get_runtime_during(self, start_time, end_time):
-        runtime = InstanceRuntime()
-
-        last_start = None  # Time the instance was last started
-        last_stop = None  # Time the instance was last stopped
-        last_event_name = None
-        in_error_state = False
-        delete_action_found = False
-
-        for event in self.events:
-            event_time = self._clamp_time(event.time, start_time, end_time)
-
-            if event.message == "Error":
-                in_error_state = True
-                continue
-
-            if event.name in ["create", "start"]:
-                last_start = event_time
-                in_error_state = False
-
-                # Count stopped time from last known stop.
-                if last_stop:
-                    runtime.total_seconds_stopped += (
-                        last_start - last_stop
-                    ).total_seconds()
-
-            if event.name == "stop":
-                last_stop = event_time
-
-                # Count running time from last known start.
-                if last_start:
-                    runtime.total_seconds_running += (
-                        last_stop - last_start
-                    ).total_seconds()
+        def run_state_machine():
+            """
+            Iterates through `self.events` to determine time
+            spent in various VM states (i.e running, stopped)
+            """
+            current_state = None
+            for event in self.events:
+                event_time = self._clamp_time(event.time, start_time, end_time)
+
+                # Error state can only be determined by the event message
+                if event.message == "Error":
+                    if current_state is None:
+                        current_state = enter_state("Error", event_time)
+                    else:
+                        current_state.exit(event_time)
+                        current_state = enter_state("Error", event.time)
+                    continue
+
+                for state in vm_states:
+                    if event.name in state.triggers:
+                        if current_state is None:
+                            current_state = state
+                            state.enter(event_time)
+                        elif state.name != current_state.name:
+                            current_state.exit(event_time)
+                            current_state = state
+                            state.enter(event_time)
+
+            # Some VM instances may have a `deleted_at` time, another trigger for the `Deleted` state
+            if self.deleted_at:
+                deleted_at_time = self._clamp_time(
+                    self.deleted_at, start_time, end_time
+                )
+                current_state.exit(deleted_at_time)
+                current_state = enter_state("Deleted", deleted_at_time)
 
-            if event.name == "delete":
-                # Some deleted instances do not have a delete event, they do
-                # however have a deleted_at timestamp.
-                # Delete event takes precedence over deleted_at.
-                delete_action_found = True
-                end_time = self._clamp_time(event_time, start_time, end_time)
-                break
+            current_state.exit(end_time)
 
-            last_event_name = event.name
+        def get_state_time(state_name):
+            for state in vm_states:
+                if state.name == state_name:
+                    return state.time_in
 
-        if self.deleted_at and not delete_action_found:
-            self.no_delete_action = True
-            end_time = self._clamp_time(self.deleted_at, start_time, end_time)
+        def enter_state(state_name, enter_time) -> State:
+            for state in vm_states:
+                if state.name == state_name:
+                    state.enter(enter_time)
+                    return state
 
-        # Handle the time since the last event.
-        if last_event_name in ["create", "start"]:
-            runtime.total_seconds_running += (end_time - last_start).total_seconds()
+        runtime = InstanceRuntime()
+        vm_states = [
+            State(state_name, state_triggers)
+            for state_name, state_triggers in (
+                ("Running", ["unshelve", "create", "start"]),
+                ("Shelved", ["shelve"]),
+                ("Stopped", ["stop"]),
+                ("Deleted", ["delete"]),
+                ("Error", []),
+            )
+        ]
 
-        if last_event_name == "stop" and not in_error_state:
-            runtime.total_seconds_stopped += (end_time - last_stop).total_seconds()
+        run_state_machine()
 
+        runtime.total_seconds_running = get_state_time("Running")
+        runtime.total_seconds_stopped = get_state_time("Stopped")
         return runtime
 
     @property

src/openstack_billing_db/tests/unit/test_instance.py

@@ -2,7 +2,7 @@
 from datetime import datetime, timedelta
 
 from openstack_billing_db.model import Instance, InstanceEvent, Database
-from openstack_billing_db.tests.unit.utils import FLAVORS, MINUTE, DAY, MONTH
+from openstack_billing_db.tests.unit.utils import FLAVORS, MINUTE, HOUR, DAY, MONTH
 
 
 def test_instance_simple_runtime():
@@ -182,6 +182,150 @@ def test_instance_stopped_and_deleted():
     assert r.total_seconds_stopped == (1 * HOUR)
 
 
+def test_instance_shelved_and_unshelved():
+    time = datetime(year=2000, month=1, day=2, hour=0, minute=0, second=0)
+    events = [
+        InstanceEvent(time=time, name="create", message=""),
+        InstanceEvent(time=time + timedelta(minutes=40), name="shelve", message=""),
+        InstanceEvent(time=time + timedelta(days=1), name="unshelve", message=""),
+    ]
+    i = Instance(
+        uuid=uuid.uuid4().hex,
+        name=uuid.uuid4().hex,
+        flavor=FLAVORS[1],
+        events=events,
+        deleted_at=time + timedelta(days=1, minutes=40),
+    )
+
+    r = i.get_runtime_during(
+        datetime(year=2000, month=1, day=1, hour=0, minute=0, second=0),
+        datetime(year=2000, month=2, day=1, hour=0, minute=0, second=0),
+    )
+
+    assert r.total_seconds_running == (40 * MINUTE) + (40 * MINUTE)
+    assert r.total_seconds_stopped == 0
+
+
+def test_instance_shelved_no_unshelved():
+    time = datetime(year=2000, month=1, day=2, hour=0, minute=0, second=0)
+    events = [
+        InstanceEvent(time=time, name="create", message=""),
+        InstanceEvent(time=time + timedelta(minutes=40), name="shelve", message=""),
+    ]
+    i = Instance(
+        uuid=uuid.uuid4().hex,
+        name=uuid.uuid4().hex,
+        flavor=FLAVORS[1],
+        events=events,
+        deleted_at=time + timedelta(days=1, minutes=40),
+    )
+
+    r = i.get_runtime_during(
+        datetime(year=2000, month=1, day=1, hour=0, minute=0, second=0),
+        datetime(year=2000, month=2, day=1, hour=0, minute=0, second=0),
+    )
+    assert r.total_seconds_running == (40 * MINUTE)
+    assert r.total_seconds_stopped == 0
+
+
+def test_instance_shelved_unshelved_stopped():
+    time = datetime(year=2000, month=1, day=2, hour=0, minute=0, second=0)
+    events = [
+        InstanceEvent(time=time, name="create", message=""),
+        InstanceEvent(time=time + timedelta(minutes=40), name="stop", message=""),
+        InstanceEvent(time=time + timedelta(days=1), name="start", message=""),
+        InstanceEvent(
+            time=time + timedelta(days=1, hours=6), name="shelve", message=""
+        ),
+        InstanceEvent(
+            time=time + timedelta(days=1, hours=12), name="unshelve", message=""
+        ),
+    ]
+    i = Instance(
+        uuid=uuid.uuid4().hex,
+        name=uuid.uuid4().hex,
+        flavor=FLAVORS[1],
+        events=events,
+        deleted_at=time + timedelta(days=2),
+    )
+
+    r = i.get_runtime_during(
+        datetime(year=2000, month=1, day=1, hour=0, minute=0, second=0),
+        datetime(year=2000, month=2, day=1, hour=0, minute=0, second=0),
+    )
+    assert r.total_seconds_running == (40 * MINUTE) + (6 * HOUR) + (12 * HOUR)
+    assert r.total_seconds_stopped == DAY - (40 * MINUTE)
+
+
+def test_instance_error_deleted():
+    time = datetime(year=2000, month=1, day=2, hour=0, minute=0, second=0)
+    events = [
+        InstanceEvent(time=time, name="create", message="Error"),
+        InstanceEvent(time=time + timedelta(hours=1), name="delete", message=""),
+    ]
+    i = Instance(
+        uuid=uuid.uuid4().hex, name=uuid.uuid4().hex, flavor=FLAVORS[1], events=events
+    )
+
+    r = i.get_runtime_during(
+        datetime(year=2000, month=1, day=1, hour=0, minute=0, second=0),
+        datetime(year=2000, month=2, day=1, hour=0, minute=0, second=0),
+    )
+    assert r.total_seconds_running == 0
+    assert r.total_seconds_stopped == 0
+
+
+def test_instance_error_restart_failed():
+    time = datetime(year=2000, month=1, day=2, hour=0, minute=0, second=0)
+    events = [
+        InstanceEvent(time=time, name="create", message=""),
+        InstanceEvent(time=time + timedelta(minutes=45), name="stop", message=""),
+        InstanceEvent(
+            time=time + timedelta(hours=1), name="start", message="Error"
+        ),  # This start period should not be counted
+        InstanceEvent(
+            time=time + timedelta(hours=1, minutes=10), name="delete", message=""
+        ),
+    ]
+    i = Instance(
+        uuid=uuid.uuid4().hex, name=uuid.uuid4().hex, flavor=FLAVORS[1], events=events
+    )
+
+    r = i.get_runtime_during(
+        datetime(year=2000, month=1, day=1, hour=0, minute=0, second=0),
+        datetime(year=2000, month=2, day=1, hour=0, minute=0, second=0),
+    )
+    assert r.total_seconds_running == 45 * MINUTE
+    assert r.total_seconds_stopped == 15 * MINUTE
+
+
+def test_instance_error_restarted():
+    time = datetime(year=2000, month=1, day=2, hour=0, minute=0, second=0)
+    events = [
+        InstanceEvent(time=time, name="create", message=""),
+        InstanceEvent(time=time + timedelta(minutes=45), name="stop", message=""),
+        InstanceEvent(
+            time=time + timedelta(hours=1), name="start", message="Error"
+        ),  # This start/stop period should not be counted
+        InstanceEvent(
+            time=time + timedelta(hours=1, minutes=15), name="start", message=""
+        ),
+        InstanceEvent(
+            time=time + timedelta(hours=1, minutes=25), name="delete", message=""
+        ),
+    ]
+    i = Instance(
+        uuid=uuid.uuid4().hex, name=uuid.uuid4().hex, flavor=FLAVORS[1], events=events
+    )
+
+    r = i.get_runtime_during(
+        datetime(year=2000, month=1, day=1, hour=0, minute=0, second=0),
+        datetime(year=2000, month=2, day=1, hour=0, minute=0, second=0),
+    )
+    assert r.total_seconds_running == 45 * MINUTE + 10 * MINUTE
+    assert r.total_seconds_stopped == 15 * MINUTE
+
+
 def test_instance_get_gpu_flavor():
     test_pci_info = [("a100", "2"), ("a100-sxm4", "4")]
     answers = [("gpu_a100", 2), ("gpu_a100sxm4", 4)]