From 0b666f054be379470aa83bfb296632de803a3e51 Mon Sep 17 00:00:00 2001
From: Filippo Pacifici <fpacifici@sentry.io>
Date: Thu, 20 Jul 2023 10:42:43 -0700
Subject: [PATCH] feat(options) Log an error when drift is detected. (#53223)

Drift is an abnormal condition but, contrarily to invalid options, we can go on and update the sane options.
Drift is only visible in the automator logs today. That is not very handy.
Logging an error generates a Sentry error we can create an alert on.
---
 src/sentry/runner/commands/configoptions.py   |  8 +++++-
 .../runner/commands/test_configoptions.py     | 27 ++++++++++++++++---
 2 files changed, 30 insertions(+), 5 deletions(-)

diff --git a/src/sentry/runner/commands/configoptions.py b/src/sentry/runner/commands/configoptions.py
index 7d7339390b50c6..7f2ea0d8538862 100644
--- a/src/sentry/runner/commands/configoptions.py
+++ b/src/sentry/runner/commands/configoptions.py
@@ -4,7 +4,7 @@
 import click
 from yaml import safe_dump, safe_load
 
-from sentry.runner.decorators import configuration
+from sentry.runner.decorators import configuration, log_options
 
 # These messages are produced more than once and referenced in tests.
 # This is the reason they are constants.
@@ -23,14 +23,19 @@ def _attempt_update(
     Updates the option if it is not drifted and if we are not in dry
     run mode.
     """
+    import logging
+
     from sentry import options
 
+    logger = logging.getLogger("sentry.options_automator")
+
     opt = options.lookup_key(key)
 
     db_value = options.get(key)
     db_value_to_print = "[REDACTED]" if opt.has_any_flag({options.FLAG_CREDENTIAL}) else db_value
     if key in drifted_options:
         click.echo(DRIFT_MSG % key)
+        logger.error("Option %s drifted and cannot be updated.", key)
         if not hide_drift:
             click.echo(DB_VALUE % key)
             # This is yaml instead of the python representation as the
@@ -82,6 +87,7 @@ def _attempt_update(
     is_flag=True,
     help="Hide the actual value of the option on DB when detecting drift.",
 )
+@log_options()
 @click.pass_context
 @configuration
 def configoptions(ctx, dry_run: bool, file: Optional[str], hide_drift: bool) -> None:
diff --git a/tests/sentry/runner/commands/test_configoptions.py b/tests/sentry/runner/commands/test_configoptions.py
index a053939852111e..c10c2de2fdebfb 100644
--- a/tests/sentry/runner/commands/test_configoptions.py
+++ b/tests/sentry/runner/commands/test_configoptions.py
@@ -86,13 +86,26 @@ def assert_not_set() -> None:
 
         def assert_output(rv):
             assert rv.exit_code == 0, rv.output
-            output = "\n".join(
+
+            # The script produces log lines when DRIFT is detected. This
+            # makes it easier to surface these as Sentry errors.
+            # This also means the output is polluted with a log line
+            # because reconfiguring the logger in the test is quite tricky
+            # as it is initialized at the beginning of the test.
+            # So we just split the output in two and check each part
+            # independently.
+            output_before_log = "\n".join(
                 [
                     SET_MSG % ("int_option", 40),
                     UPDATE_MSG % ("str_option", "old value", "new value"),
                     SET_MSG % ("map_option", {"a": 1, "b": 2}),
                     SET_MSG % ("list_option", [1, 2]),
                     DRIFT_MSG % "drifted_option",
+                ]
+            )
+
+            output_after_log = "\n".join(
+                [
                     DB_VALUE % "drifted_option",
                     "- 1",
                     "- 2",
@@ -101,7 +114,8 @@ def assert_output(rv):
                     CHANNEL_UPDATE_MSG % "change_channel_option",
                 ]
             )
-            assert output in rv.output
+            assert output_before_log in rv.output
+            assert output_after_log in rv.output
 
         assert_not_set()
         rv = self.invoke(
@@ -153,13 +167,17 @@ def test_sync(self):
             "sync",
         )
         assert rv.exit_code == 0, rv.output
-        output = "\n".join(
+        output_before_log = "\n".join(
             [
                 SET_MSG % ("int_option", 40),
                 UPDATE_MSG % ("str_option", "old value", "new value"),
                 SET_MSG % ("map_option", {"a": 1, "b": 2}),
                 SET_MSG % ("list_option", [1, 2]),
                 DRIFT_MSG % "drifted_option",
+            ]
+        )
+        output_after_log = "\n".join(
+            [
                 DB_VALUE % "drifted_option",
                 "- 1",
                 "- 2",
@@ -170,7 +188,8 @@ def test_sync(self):
             ]
         )
 
-        assert output in rv.output
+        assert output_before_log in rv.output
+        assert output_after_log in rv.output
 
         assert options.get("int_option") == 40
         assert options.get("str_option") == "new value"