Add more logging to plugin sync and install (#3730)

# What this PR does
Add logging to process for syncing OnCall backend with Grafana to help
troubleshoot issues in self-hosted setups.


## Which issue(s) this PR fixes

## Checklist

- [ ] Unit, integration, and e2e (if applicable) tests updated
- [x] Documentation added (or `pr:no public docs` PR label added if not
required)
- [x] `CHANGELOG.md` updated (or `pr:no changelog` PR label added if not
required)

CHANGELOG.md

@@ -7,6 +7,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ## Unreleased
 
+### Added
+
+- Improved logging during plugin sync and install with Grafana @mderynck ([#3730](https://github.com/grafana/oncall/pull/3730))
+
 ## v1.3.92 (2024-01-23)
 
 Maintenance release

engine/apps/auth_token/auth.py

@@ -104,9 +104,11 @@ class BasePluginAuthentication(BaseAuthentication):
         try:
             context = dict(json.loads(request.headers.get("X-Grafana-Context")))
         except (ValueError, TypeError):
+            logger.info("auth request user not found - missing valid X-Grafana-Context")
             return None
 
         if "UserId" not in context and "UserID" not in context:
+            logger.info("auth request user not found - X-Grafana-Context missing UserID")
             return None
 
         try:
@@ -117,6 +119,7 @@ class BasePluginAuthentication(BaseAuthentication):
         try:
             return organization.users.get(user_id=user_id)
         except User.DoesNotExist:
+            logger.info(f"auth request user not found - user_id={user_id}")
             return None
 
 

engine/apps/grafana_plugin/views/install.py

@@ -1,3 +1,5 @@
+import logging
+
 from rest_framework import status
 from rest_framework.request import Request
 from rest_framework.response import Response
@@ -8,6 +10,8 @@ from apps.user_management.models import Organization
 from apps.user_management.sync import sync_organization
 from common.api_helpers.mixins import GrafanaHeadersMixin
 
+logger = logging.getLogger(__name__)
+
 
 class InstallView(GrafanaHeadersMixin, APIView):
     authentication_classes = (BasePluginAuthentication,)
@@ -21,6 +25,11 @@ class InstallView(GrafanaHeadersMixin, APIView):
         organization.deleted_at = None
         organization.api_token = self.instance_context["grafana_token"]
         organization.save(update_fields=["api_token", "deleted_at"])
+        logger.info(f"install - grafana_token replaced org={organization.pk}")
 
         sync_organization(organization)
+        logger.info(
+            f"install - sync organization finished org={organization.pk} "
+            f"token_status={organization.api_token_status}"
+        )
         return Response(status=status.HTTP_204_NO_CONTENT)

engine/apps/grafana_plugin/views/status.py

@@ -1,3 +1,5 @@
+import logging
+
 from django.conf import settings
 from rest_framework.request import Request
 from rest_framework.response import Response
@@ -11,6 +13,8 @@ from apps.user_management.models import Organization
 from common.api_helpers.mixins import GrafanaHeadersMixin
 from common.api_helpers.utils import create_engine_url
 
+logger = logging.getLogger(__name__)
+
 
 class StatusView(GrafanaHeadersMixin, APIView):
     authentication_classes = (
@@ -19,8 +23,13 @@ class StatusView(GrafanaHeadersMixin, APIView):
     )
 
     def post(self, request: Request) -> Response:
+        logger.info(
+            f"authenticated via {type(request.successful_authenticator)}, user=[{request.user}] "
+            f"org=[{request.auth.organization.stack_slug if request.auth.organization else None}]"
+        )
+
         """
-        Called asyncronounsly on each start of the plugin
+        Called asynchronously on each start of the plugin
         Checks if plugin is correctly installed and async runs a task
         to sync users, teams and org
         """
@@ -42,7 +51,12 @@ class StatusView(GrafanaHeadersMixin, APIView):
         if organization:
             is_installed = True
             token_ok = organization.api_token_status == Organization.API_TOKEN_STATUS_OK
+            logger.info(
+                f"Status - check token org={organization.pk} status={organization.api_token_status} "
+                f"token_ok={token_ok}"
+            )
             if organization.is_moved:
+                logger.info(f"Organization Moved! org={organization.pk}")
                 api_url = create_engine_url("", override_base=organization.migration_destination.oncall_backend_url)
         else:
             allow_signup = DynamicSetting.objects.get_or_create(
@@ -51,6 +65,7 @@ class StatusView(GrafanaHeadersMixin, APIView):
 
         # If user is not present in OnCall database, set token_ok to False, which will trigger reinstall
         if not request.user:
+            logger.info(f"Status - user not found org={organization.pk} " f"setting token_status to PENDING")
             token_ok = False
             organization.api_token_status = Organization.API_TOKEN_STATUS_PENDING
             organization.save(update_fields=["api_token_status"])

engine/apps/user_management/sync.py

@@ -42,6 +42,7 @@ def _sync_organization(organization: Organization) -> None:
         rbac_is_enabled = grafana_api_client.is_rbac_enabled_for_organization()
 
     organization.is_rbac_permissions_enabled = rbac_is_enabled
+    logger.info(f"RBAC status org={organization.pk} rbac_enabled={organization.is_rbac_permissions_enabled}")
 
     _sync_instance_info(organization)
 
@@ -59,6 +60,7 @@ def _sync_organization(organization: Organization) -> None:
             )
     else:
         organization.api_token_status = Organization.API_TOKEN_STATUS_FAILED
+        logger.warning(f"Sync not successful org={organization.pk} token_status=FAILED")
 
     organization.save(
         update_fields=[