Retry telemetry registration quickly instead of hourly

TelemetryService only retried every iter_min_period (up to 1 hour), but
exordos-bootstrap sets the VS variables it depends on with no systemd
ordering guarantee relative to ec-gservice, so the very first attempt can
silently skip (variables not set yet). With a 1-hour retry period, a
managed realm's ecosystem-side provisioning_timeout (also defaulting to
1 hour) can fire before the next attempt, permanently erroring the realm.

Retry starting at 30s until registration is confirmed, then relax to the
caller's steady-state period immediately. Stands with no network access at
all would otherwise retry every 30s forever, so each failed attempt
doubles the retry period, capped at the steady-state period, until
registration succeeds. Also bump the "variables not configured" log from
DEBUG to INFO so this condition is visible in normal logs.

Signed-off-by: George Melikov <mail@gmelikov.ru>

Author: gmelikov

exordos_core/telemetry/service.py

@@ -40,6 +40,22 @@
 TELEMETRY_TIMEOUT = 30
 TELEMETRY_POOL_SIZE = 1
 
+# Initial retry cadence used until the stand has successfully registered
+# with the ecosystem at least once. exordos-bootstrap (which sets the VS
+# variables this service depends on) has no systemd ordering guarantee
+# relative to ec-gservice, so the very first iteration can race ahead of
+# the variables being set. Falling back to the full iter_min_period (can be
+# as long as an hour) in that case would leave the stand stuck in
+# PROVISIONING for a long time, so we start retrying quickly.
+#
+# Stands with no network access at all would otherwise keep retrying every
+# TELEMETRY_RETRY_PERIOD forever, so on every failed attempt the period is
+# doubled (TELEMETRY_RETRY_BACKOFF_FACTOR), up to the caller's steady-state
+# period. It resets back to TELEMETRY_RETRY_PERIOD once registration
+# succeeds, then relaxes to the steady-state period.
+TELEMETRY_RETRY_PERIOD = 30
+TELEMETRY_RETRY_BACKOFF_FACTOR = 2
+
 
 class TelemetryService(basic.BasicService):
     """Periodically collects and sends telemetry data to the ecosystem."""
@@ -49,6 +65,13 @@ def __init__(self, *args, **kwargs):
         self._client = bazooka.Client(default_timeout=TELEMETRY_TIMEOUT)
         self._executor = futures.ThreadPoolExecutor(max_workers=TELEMETRY_POOL_SIZE)
         self._pending_future = None
+        # Steady-state period requested by the caller (e.g. 1 hour). Until
+        # the stand registers successfully we back off from
+        # TELEMETRY_RETRY_PERIOD towards this value instead; see the
+        # comment on TELEMETRY_RETRY_PERIOD above.
+        self._steady_period = self._iter_min_period
+        self._registered = False
+        self._iter_min_period = TELEMETRY_RETRY_PERIOD
 
     def _get_variable_value(self, var_uuid):
         """Read variable value from ValuesStore by UUID."""
@@ -227,6 +250,20 @@ def _register_stand(self, endpoint, realm_uuid, realm_secret):
         )
         LOG.info("Stand registered in ecosystem successfully")
 
+    def _mark_registered(self):
+        """Relax the retry cadence once the stand is confirmed registered."""
+        self._registered = True
+        self._iter_min_period = self._steady_period
+
+    def _backoff_retry(self):
+        """Grow the retry cadence towards the steady-state period on failure."""
+        if self._registered:
+            return
+        self._iter_min_period = min(
+            self._iter_min_period * TELEMETRY_RETRY_BACKOFF_FACTOR,
+            self._steady_period,
+        )
+
     def _send_telemetry(self, endpoint, realm_uuid, realm_secret, data):
         """Send telemetry data to the ecosystem endpoint."""
         url = f"{endpoint}/api/ecosystem/v1/realms/{realm_uuid}/actions/push_telemetry/invoke"
@@ -240,6 +277,7 @@ def _send_telemetry(self, endpoint, realm_uuid, realm_secret, data):
                 auth=auth,
             )
             LOG.debug("Telemetry sent successfully")
+            self._mark_registered()
         except bazooka_exc.ForbiddenError:
             LOG.warning("Stand is not registered, attempting registration")
             try:
@@ -251,10 +289,13 @@ def _send_telemetry(self, endpoint, realm_uuid, realm_secret, data):
                     auth=auth,
                 )
                 LOG.debug("Telemetry sent successfully after registration")
+                self._mark_registered()
             except Exception:
                 LOG.exception("Failed to register stand or send telemetry")
+                self._backoff_retry()
         except Exception:
             LOG.exception("Failed to send telemetry")
+            self._backoff_retry()
 
     def _check_pending_future(self):
         """Clear completed future to allow the next submission."""
@@ -281,7 +322,11 @@ def _iteration(self):
             realm_secret = self._get_variable_value(c.VAR_REALM_SECRET_UUID)
 
             if not all([ecosystem_endpoint, realm_uuid, realm_secret]):
-                LOG.debug("Telemetry variables are not configured, skipping")
+                self._backoff_retry()
+                LOG.info(
+                    "Telemetry variables are not configured yet, will retry in %ss",
+                    self._iter_min_period,
+                )
                 return
 
             # Collect telemetry data synchronously, send asynchronously

exordos_core/user_api/iam/api/controllers.py

@@ -17,18 +17,18 @@
 import errno
 import logging
 import mimetypes
-import uuid as sys_uuid
 from os import path as os_path
 import re
 import string
 import typing as tp
 from urllib import parse as urllib_parse
+import uuid as sys_uuid
 
 from authlib.integrations import requests_client
+from gcl_iam import exceptions as gcl_iam_e
 from gcl_iam import rules
 from gcl_iam.api import controllers as iam_controllers
 from gcl_iam.api import field_perms as iam_fp
-from gcl_iam import exceptions as gcl_iam_e
 import jinja2
 import pyotp
 from restalchemy.api import actions
@@ -310,9 +310,7 @@ def _get_request_iam_client(self) -> models.IamClient | None:
             # a client token; attribute it to the default client.
             return models.IamClient.objects.get_one_or_none(
                 filters={
-                    "uuid": ra_filters.EQ(
-                        sys_uuid.UUID(common_c.DEFAULT_CLIENT_UUID)
-                    )
+                    "uuid": ra_filters.EQ(sys_uuid.UUID(common_c.DEFAULT_CLIENT_UUID))
                 }
             )