diff --git a/requirements-build.txt b/requirements-build.txt index a4d352a8..3dac905e 100644 --- a/requirements-build.txt +++ b/requirements-build.txt @@ -486,6 +486,7 @@ django==5.2.8 \ # django-crum # django-filter # django-generate-series + # django-guid # django-solo # django-weasyprint # djangorestframework @@ -509,6 +510,10 @@ django-generate-series==0.5.0 \ --hash=sha256:54e33e5aba69be75f591bda970421dee9f1c5feeb84c20d8cee634bcc0e249bc \ --hash=sha256:8cced6473ba75aed5e1e2ecd6f5426d11d33926e86d2630dabe9c424b7a6da8a # via -r requirements-pinned.txt +django-guid==3.5.2 \ + --hash=sha256:0f812a837579031c7db8524b07e498f65b5fcf191857c1f7fb5414a0ceb584fa \ + --hash=sha256:cadbc929bfa2b19c6f9e847da3e095ebebe1124adef92f0af317f963ee51a6cb + # via -r requirements-pinned.txt django-solo==2.4.0 \ --hash=sha256:62e9c7d929620a61848515839833750ca142840051595cf5c8e617dcefc9e5cf \ --hash=sha256:ec92dc00aec75034a3f93b3a85152e57c4b03d7987f8cfd0ea8a47cc6e3c2084 @@ -676,6 +681,7 @@ packaging==25.0 \ --hash=sha256:d443872c98d677bf60f6a1f2f8c1cb748e8fe762d2bf9d3148b5599295b0fc4f # via # ansible-runner + # django-guid # pytest pexpect==4.9.0 \ --hash=sha256:7236d1e080e4936be2dc3e326cec0af72acf9212a7e1d060210e70a47e253523 \ diff --git a/requirements-pinned.txt b/requirements-pinned.txt index 490d7e97..601734b6 100644 --- a/requirements-pinned.txt +++ b/requirements-pinned.txt @@ -8,6 +8,7 @@ django-ansible-base==2025.10.20 django-cors-headers==4.9.0 django-filter==25.2 django-generate-series==0.5.0 +django-guid==3.5.2 django-solo==2.4.0 django-weasyprint==2.4.0 djangorestframework==3.16.1 diff --git a/requirements.txt b/requirements.txt index 787b386c..593c7284 100644 --- a/requirements.txt +++ b/requirements.txt @@ -8,6 +8,7 @@ django-ansible-base==2025.10.20 django-cors-headers==4.9.0 django-filter==25.2 django-generate-series==0.5.0 +django-guid==3.5.2 django-solo==2.4.0 django-weasyprint==2.4.0 djangorestframework==3.16.1 diff --git a/src/backend/apps/aap_auth/aap_auth.py b/src/backend/apps/aap_auth/aap_auth.py index 803989ba..59b18814 100644 --- a/src/backend/apps/aap_auth/aap_auth.py +++ b/src/backend/apps/aap_auth/aap_auth.py @@ -13,7 +13,7 @@ from backend.apps.users.models import User from backend.apps.users.schemas import UserResponseSchema -logger = logging.getLogger("automation-dashboard") +logger = logging.getLogger("automation-dashboard.aap_auth") def memoize(func): @@ -35,8 +35,9 @@ class AAPAuth: # Handles AAP authentication and user management def __init__(self): - # Initialize authentication settings from config + logger.info("Initializing AAPAuth") auth_settings = AAPAuthSettings(**settings.AAP_AUTH_PROVIDER) + logger.debug(f"Auth settings: {auth_settings}") setting_url = auth_settings.url[:-1] if auth_settings.url.endswith('/') else auth_settings.url self.name = auth_settings.name @@ -50,59 +51,65 @@ def __init__(self): self.user_data_uri = user_data_uri self.check_ssl = auth_settings.check_ssl + logger.info("Fetching OAuth endpoints") o_endpoints = self.get_o_endpoints() + logger.debug(f"OAuth endpoints: {o_endpoints}") self.authorize_uri = o_endpoints["authorize_uri"] self.token_uri = o_endpoints["token_uri"] self.revoke_token_uri = o_endpoints["revoke_token_uri"] - # Optionally suppress urllib3 SSL warnings if not settings.SHOW_URLLIB3_INSECURE_REQUEST_WARNING: urllib3.disable_warnings(urllib3.exceptions.InsecureRequestWarning) - + logger.info("AAPAuth initialized successfully") def ping(self, url: str) -> Response: - logger.info(f"Try to obtain OAuth endpoint {url}") + logger.info(f"Trying to obtain OAuth endpoint: {url}") try: response = requests.get( url=url, verify=self.check_ssl, allow_redirects=False, timeout=3) + logger.debug(f"Ping response status: {response.status_code}") except requests.exceptions.HTTPError as e: - logger.error(f'GET request {url} failed with exception {e}') + logger.error(f'GET request {url} failed: {e}') raise AuthenticationFailed(f"Failed request to {url}") if response.ok: - logger.info(f"Successfully obtained OAuth endpoint {url}") + logger.info(f"Successfully obtained OAuth endpoint: {url}") return response - # Cache the OAuth endpoints to avoid pinging the server on every call @memoize def get_o_endpoints(self): + logger.info("Getting OAuth endpoints") url = f"{self.url}/o/" response = self.ping(url) + logger.debug(f"First endpoint response: {response.ok}") if response.ok: result = { 'authorize_uri': '/o/authorize/', 'token_uri': '/o/token/', 'revoke_token_uri': '/o/revoke_token/' } + logger.info("OAuth endpoints found at /o/") return result url = f"{self.url}/api/o/" response = self.ping(url) + logger.debug(f"Second endpoint response: {response.ok}") if response.ok: result = { 'authorize_uri': '/api/o/authorize/', 'token_uri': '/api/o/token/', 'revoke_token_uri': '/api/o/revoke_token/' } + logger.info("OAuth endpoints found at /api/o/") return result logger.error("Failed to obtain OAuth endpoints after multiple attempts.") raise AuthenticationFailed("Authorization failed: Unable to find a valid OAuth endpoint.") def ui_data(self) -> dict[str, str]: - # Returns data needed for UI authorization flow + logger.debug("Preparing UI data for authorization flow") return { 'name': self.name, 'url': f'{self.url}{self.authorize_uri}', @@ -113,7 +120,8 @@ def ui_data(self) -> dict[str, str]: } def _aap_authorize(self, params: dict[str, str]) -> AAPToken: - # Requests an AAP token using provided parameters + logger.info("Requesting AAP token") + logger.debug(f"Token request uri: {self.url}{self.token_uri}") response = requests.post( url=f"{self.url}{self.token_uri}", data=params, @@ -121,20 +129,24 @@ def _aap_authorize(self, params: dict[str, str]) -> AAPToken: allow_redirects=False, timeout=30, ) + logger.debug(f"AAP token response status: {response.status_code}") if not response.ok: - logger.error("An error occurred obtaining AAP token. %s", response.content) + logger.error("Error obtaining AAP token: %s", response.content) raise AuthenticationFailed("Obtaining of AAP token failed. An error occurred connecting to AAP authorization server.") token_result = response.json() + logger.debug(f"Token result: {token_result}") access_token = token_result.get("access_token", None) refresh_token = token_result.get("refresh_token", None) if access_token is None or refresh_token is None: + logger.error("Invalid token response from AAP") raise AuthenticationFailed("Obtaining of AAP token failed. Invalid response from AAP.") return AAPToken(**token_result) def authorize(self, code: str, redirect_uri: str) -> dict[str, JwtUserToken | JwtUserRefreshToken]: - # Exchanges authorization code for tokens and user info + logger.info("Authorizing user") + logger.debug(f"Authorization code: {code}, redirect_uri: {redirect_uri}") token_params = { "client_id": self.client_id, "client_secret": self.client_secret, @@ -145,10 +157,12 @@ def authorize(self, code: str, redirect_uri: str) -> dict[str, JwtUserToken | Jw aap_token = self._aap_authorize(token_params) user = self.get_user_data(aap_token) jwt_token = JWTToken() + logger.info("User authorized successfully") return jwt_token.acquire_token_pair(aap_token=aap_token, user=user) def get_user_data(self, aap_token: AAPToken) -> User: - # Fetches user data from AAP using the access token + logger.info("Fetching user data from AAP") + logger.debug(f"Access token: {aap_token.access_token}") headers = { 'Authorization': f'{aap_token.token_type} {aap_token.access_token}', 'Content-Type': 'application/json', @@ -163,26 +177,31 @@ def get_user_data(self, aap_token: AAPToken) -> User: timeout=30, headers=headers ) + logger.debug(f"User data response status: {user_response.status_code}") user_response.raise_for_status() except requests.exceptions.HTTPError as e: - logger.error("An error occurred obtaining AAP user. %s", e.response.content) + logger.error("Error obtaining AAP user: %s", e.response.content) raise AuthenticationFailed("An error occurred obtaining AAP user.") except requests.exceptions.RequestException as e: logger.error(f"Failed to validate token with AAP: {str(e)}") raise ValueError("Failed to validate token with AAP") users = UserResponseSchema(**user_response.json()) + logger.debug(f"User response schema: {users}") if users.count != 1: - logger.error(f"Failed to retrieve AAP user. {str(users)}") + logger.error(f"Failed to retrieve AAP user: {str(users)}") raise ValueError("Failed to retrieve AAP user.") + logger.info("User data fetched successfully") return User.create_or_update_aap_user(users.results[0]) def refresh_token(self, refresh_token: str) -> dict[str, JwtUserToken | JwtUserRefreshToken]: - # Refreshes JWT tokens using the AAP refresh token + logger.info("Refreshing JWT token") + logger.debug(f"Refresh token: {refresh_token}") jwt_token = JWTToken() refresh_token = jwt_token.decode_refresh_token(token=refresh_token) if refresh_token is None: + logger.error("Refresh token is invalid") raise NotAuthenticated("Refresh token is invalid.") token_params = { @@ -195,17 +214,19 @@ def refresh_token(self, refresh_token: str) -> dict[str, JwtUserToken | JwtUserR user = self.get_user_data(aap_token) refresh_token.revoke_token() - + logger.info("JWT token refreshed successfully") return jwt_token.acquire_token_pair(aap_token=aap_token, user=user) def logout(self, access_token: str) -> dict[str, any]: - # Revokes the AAP token and logs out the user + logger.info("Logging out user") + logger.debug(f"Access token: {access_token}") token = JwtUserToken.get_user_token(access_token) result = { "success": True, "message": "", } if token is None or token.id is None: + logger.error("Invalid token for logout") raise AuthenticationFailed("Invalid token.") token_params = { @@ -221,14 +242,16 @@ def logout(self, access_token: str) -> dict[str, any]: allow_redirects=False, timeout=30, ) + logger.debug(f"Logout response status: {response.status_code}") if not response.ok: - logger.error("An error occurred revoking AAP token. %s", response.content) + logger.error("Error revoking AAP token: %s", response.content) result["success"] = False result["message"] = response.content result["status_code"] = response.status_code return result token.revoke_token() + logger.info("User logged out successfully") result["success"] = True return result diff --git a/src/backend/apps/aap_auth/authentication.py b/src/backend/apps/aap_auth/authentication.py index 17b77cbc..3207aac0 100644 --- a/src/backend/apps/aap_auth/authentication.py +++ b/src/backend/apps/aap_auth/authentication.py @@ -7,42 +7,52 @@ from backend.apps.aap_auth.jwt_token import JWTToken -logger = logging.getLogger("automation-dashboard") +logger = logging.getLogger("automation_dashboard.auth") def enforce_csrf(request): """ Enforce CSRF validation. """ + logger.info("Starting CSRF validation.") check = CSRFCheck(request) check.process_request(request) reason = check.process_view(request, None, (), {}) if reason: + logger.error('CSRF Failed: %s' % reason) raise exceptions.PermissionDenied('CSRF Failed: %s' % reason) class AAPAuthentication(BaseAuthentication): def authenticate(self, request: Request): + logger.info("Starting authentication process") token = request.COOKIES.get(settings.AUTH_COOKIE_ACCESS_TOKEN_NAME) or None + logger.debug(f"Token from cookies: {token}") if token is None: + logger.info("No token found in cookies") return None - if len(token) < 10: # Basic length check + if len(token) < 10: + logger.warning("Token length is too short") return None + logger.debug("Attempting to decode token") jwt_token = JWTToken() db_token = jwt_token.decode_token(token) if db_token is None: + logger.warning("Failed to decode token") return None if not db_token.user.is_active: + logger.warning("User is not active") return None enforce_csrf(request) - + logger.info("Authentication successful") return db_token.user, token def authenticate_header(self, request: Request) -> str: + logger.debug("Returning authentication header") return "Bearer" diff --git a/src/backend/apps/aap_auth/jwt_token.py b/src/backend/apps/aap_auth/jwt_token.py index b3995d30..69ae447b 100644 --- a/src/backend/apps/aap_auth/jwt_token.py +++ b/src/backend/apps/aap_auth/jwt_token.py @@ -1,37 +1,45 @@ +import logging import uuid from datetime import datetime, timedelta from typing import Dict import jwt import pytz +from django.conf import settings from backend.apps.aap_auth.models import JwtUserToken, JwtUserRefreshToken from backend.apps.aap_auth.schema import AAPToken from backend.apps.users.models import User -from django.conf import settings + +logger = logging.getLogger("automation_dashboard.jwt") class JWTToken: # Handles JWT token creation, decoding, and management def __init__(self): - # Initialize token lifetimes and algorithm from settings + logger.info("Initializing JWTToken") self.access_token_lifetime_seconds = settings.JWT_ACCESS_TOKEN_LIFETIME_SECONDS self.refresh_token_lifetime_seconds = settings.JWT_REFRESH_TOKEN_LIFETIME_SECONDS self.now = datetime.now(pytz.utc) self.algorithm = 'HS256' + logger.debug(f"Access token lifetime: {self.access_token_lifetime_seconds}, " + f"Refresh token lifetime: {self.refresh_token_lifetime_seconds}, " + f"Algorithm: {self.algorithm}") @property def jti(self) -> str: - # Generates a unique token identifier - return uuid.uuid4().hex + jti = uuid.uuid4().hex + logger.debug(f"Generated JTI: {jti}") + return jti def _generate_token(self, payload: Dict[str, any], secret_key: str) -> str: - # Encodes payload into a JWT using the secret key + logger.debug(f"Generating token with payload: {payload}") return jwt.encode(payload, secret_key, algorithm=self.algorithm) def get_payload(self, user: User, lifetime_seconds: int, jti: str) -> Dict[str, any]: exp = self.now + timedelta(seconds=lifetime_seconds) + logger.debug(f"Creating payload for user: {user.username}, exp: {exp}, jti: {jti}") return { 'sub': user.username, 'iat': self.now, @@ -40,10 +48,12 @@ def get_payload(self, user: User, lifetime_seconds: int, jti: str) -> Dict[str, } def acquire_token(self, user: User, aap_token: AAPToken) -> JwtUserToken: + logger.info(f"Acquiring access token for user: {user.username}") jti = self.jti payload = self.get_payload(user, self.access_token_lifetime_seconds, jti) token = self._generate_token(payload=payload, secret_key=jti) user.log_login() + logger.debug(f"Access token generated for user: {user.username}, jti: {jti}") return JwtUserToken.create_token( user=user, aap_token=aap_token, @@ -53,10 +63,11 @@ def acquire_token(self, user: User, aap_token: AAPToken) -> JwtUserToken: ) def acquire_refresh_token(self, user: User, access_token: JwtUserToken) -> JwtUserRefreshToken: - # Creates and stores a JWT refresh token for the user + logger.info(f"Acquiring refresh token for user: {user.username}") jti = self.jti payload = self.get_payload(user, self.refresh_token_lifetime_seconds, jti) token = self._generate_token(payload=payload, secret_key=jti) + logger.debug(f"Refresh token generated for user: {user.username}, jti: {jti}") return JwtUserRefreshToken.create_token( user=user, access_token=access_token, @@ -66,35 +77,46 @@ def acquire_refresh_token(self, user: User, access_token: JwtUserToken) -> JwtUs ) def acquire_token_pair(self, user: User, aap_token: AAPToken) -> dict[str, JwtUserToken | JwtUserRefreshToken]: - # Returns a dictionary with both access and refresh tokens + logger.info(f"Acquiring token pair for user: {user.username}") access_token = self.acquire_token(user=user, aap_token=aap_token) refresh_token = self.acquire_refresh_token(user=user, access_token=access_token) + logger.debug(f"Token pair acquired for user: {user.username}") return { "access_token": access_token, "refresh_token": refresh_token, } def _decode(self, token: str, secret_key: str) -> Dict[str, any] | None: - # Decodes a JWT and returns its payload, or None if invalid + logger.debug(f"Decoding token.") try: return jwt.decode(token, secret_key, [self.algorithm]) - except jwt.InvalidTokenError: + except jwt.InvalidTokenError as e: + logger.warning(f"Invalid token error: {e}") return None def decode_token(self, token: str) -> JwtUserToken | None: - # Validates and returns the access token object if valid + logger.info("Decoding access token") db_token = JwtUserToken.get_user_token(token=token) if db_token is None or db_token.id is None: + logger.warning("Access token not found or invalid") return None decoded_token = self._decode(token=token, secret_key=db_token.jti) - return db_token if decoded_token else None + if decoded_token: + logger.debug("Access token decoded successfully") + return db_token + else: + logger.warning("Failed to decode access token") + return None def decode_refresh_token(self, token: str) -> JwtUserRefreshToken | None: - # Validates and returns the refresh token object if valid and matches access token + logger.info("Decoding refresh token") db_token = JwtUserRefreshToken.get_user_token(token=token) if db_token is None or db_token.id is None: + logger.warning("Refresh token not found or invalid") return None decoded_token = self._decode(token=token, secret_key=db_token.jti) if decoded_token is None: + logger.warning("Failed to decode refresh token") return None + logger.debug("Refresh token decoded successfully") return db_token diff --git a/src/backend/apps/clusters/connector.py b/src/backend/apps/clusters/connector.py index 52ff7185..1f70c70b 100644 --- a/src/backend/apps/clusters/connector.py +++ b/src/backend/apps/clusters/connector.py @@ -1,13 +1,14 @@ import datetime +import json import logging from urllib.parse import urlsplit import pytz -from django.conf import settings import requests -from django.db import transaction import urllib3 -import json +from django.conf import settings +from django.db import transaction +from requests.auth import HTTPBasicAuth from backend.apps.clusters.encryption import decrypt_value, encrypt_value from backend.apps.clusters.models import ( @@ -19,7 +20,7 @@ ) from backend.apps.clusters.schemas import ClusterSchema -logger = logging.getLogger("automation-reports") +logger = logging.getLogger("automation_dashboard.clusters.connector") class ApiConnector: @@ -31,7 +32,7 @@ def __init__(self, until: datetime.datetime | None = None, managed: bool = False): - # Optionally suppress urllib3 SSL warnings + logger.info(f"Initializing ApiConnector for cluster: {cluster.__str__()}") if not settings.SHOW_URLLIB3_INSECURE_REQUEST_WARNING: urllib3.disable_warnings(urllib3.exceptions.InsecureRequestWarning) @@ -40,10 +41,13 @@ def __init__(self, self.managed = managed self.access_token = decrypt_value(cluster.access_token) + logger.debug(f"Access token decrypted for cluster: {cluster.__str__()}") try: cluster_sync_data = ClusterSyncStatus.objects.get(cluster=self.cluster) + logger.info("ClusterSyncStatus found for cluster.") except ClusterSyncStatus.DoesNotExist: + logger.warning("ClusterSyncStatus not found, creating new.") cluster_sync_data = ClusterSyncStatus(cluster=self.cluster) self.cluster_sync_data = cluster_sync_data @@ -51,11 +55,14 @@ def __init__(self, if self.managed: self.since = since + logger.debug("Managed mode: using provided since value.") else: if since is not None: self.since = since + logger.debug("Since value provided, using it.") elif self.cluster_sync_data.last_job_finished_date is not None and self.managed is False: self.since = self.cluster_sync_data.last_job_finished_date + logger.debug("Using last_job_finished_date from sync data.") else: ''' Due to the possibility of a lot of data, @@ -63,29 +70,32 @@ def __init__(self, ''' initial_sync_days = getattr(settings, "INITIAL_SYNC_DAYS", 1) initial_sync_since = getattr(settings, "INITIAL_SYNC_SINCE", None) - _date = None - if initial_sync_since is not None: try: _date = datetime.datetime.fromisoformat(initial_sync_since) + logger.debug("Parsed INITIAL_SYNC_SINCE from settings.") except ValueError: + logger.warning("Failed to parse INITIAL_SYNC_SINCE, using fallback.") _date = None - if _date is None: _date = datetime.datetime.now(pytz.UTC) - datetime.timedelta(days=initial_sync_days) - - self.since = datetime.datetime.combine(_date.astimezone(pytz.UTC), datetime.datetime.min.time()).astimezone(pytz.UTC) + logger.debug("Using fallback initial sync date.") + self.since = datetime.datetime.combine(_date.astimezone(pytz.UTC), + datetime.datetime.min.time()).astimezone(pytz.UTC) + logger.info(f"Initial sync since: {self.since}") @property def headers(self): + logger.debug("Generating request headers.") return { 'Authorization': f'Bearer {self.access_token}', 'Content-Type': 'application/json', 'Accept': 'application/json', } - def _reauth(self, timeout=None): + def _reauthorize(self, timeout=None): + logger.info("Starting token refresh process.") url = f'{self.cluster.base_url}{self.cluster.oauth_token_url}' refresh_token = decrypt_value(self.cluster.refresh_token) client_id = self.cluster.client_id @@ -99,7 +109,8 @@ def _reauth(self, timeout=None): 'Content-Type': 'application/x-www-form-urlencoded', 'Accept': 'application/json', } - auth = requests.auth.HTTPBasicAuth(client_id, client_secret) + auth = HTTPBasicAuth(client_id, client_secret) + logger.debug(f"Token refresh POST data: {data}") try: response = requests.post( url=url, @@ -112,7 +123,8 @@ def _reauth(self, timeout=None): logger.error(f'Token refresh POST request failed with exception {e}') return False if not response.ok: - logger.error(f'Token refresh POST request failed with status {response.status_code} url={url}, text={json.dumps(response.text)}') + logger.error( + f'Token refresh POST request failed with status {response.status_code} url={url}, text={json.dumps(response.text)}') return False logger.info(f'Token refresh POST request succeeded with status {response.status_code}') resp = response.json() @@ -121,17 +133,21 @@ def _reauth(self, timeout=None): self.cluster.refresh_token = encrypt_value(resp["refresh_token"]) self.access_token = resp['access_token'] self.cluster.save() + logger.debug("Cluster tokens updated and saved.") return True + def _get_request(self, url, timeout=None): + return requests.get( + url=url, + verify=self.cluster.verify_ssl, + timeout=timeout if timeout is not None else self.timeout, + headers=self.headers) + def _get_with_reauth(self, url, timeout=None): # try 1st time try: - response = requests.get( - url=url, - verify=self.cluster.verify_ssl, - timeout=timeout if timeout is not None else self.timeout, - headers=self.headers) + response = self._get_request(url, timeout) except requests.exceptions.ConnectionError as e: # begin mock testing block ------------------------ # "return None" makes code behave like all is OK, and AAP returned empty json ("{}"). @@ -145,48 +161,51 @@ def _get_with_reauth(self, url, timeout=None): except requests.exceptions.RequestException as e: logger.error(f'GET request failed with exception {e}') return None + logger.debug(f"First GET response status: {response.status_code}") if response.ok: return response - # Try to re-auth only after 401 error logger.error(f'GET request failed with status {response.status_code}') if response.status_code != 401: return response - self._reauth() + logger.info("401 received, attempting re-authentication.") + self._reauthorize() - # try 2nd time try: - response = requests.get( - url=url, - verify=self.cluster.verify_ssl, - timeout=timeout if timeout is not None else self.timeout, - headers=self.headers) + response = self._get_request(url, timeout) except requests.exceptions.RequestException as e: - logger.error( f'GET request failed with exception {e}') + logger.error(f'GET request failed with exception {e}') return None - logger.error(f'GET after reauth response.status_code={response.status_code}') - return response + logger.debug(f"Second GET response status: {response.status_code}") + return response def execute_get_one(self, url, timeout=None): logger.info(f'Executing GET request to {url}') response = self._get_with_reauth(url, timeout=timeout) if response is None or not response.ok: + logger.warning(f"GET request to {url} failed or returned no response.") return None product_name = response.headers.get("X-Api-Product-Name", None) + logger.debug(f"Product name from headers: {product_name}") if product_name is None or product_name == "AWX": + logger.error("Not supported product.") raise Exception("Not supported product.") response = response.json() + logger.debug(f"GET response JSON: {response}") return response def execute_get(self, endpoint): + logger.info(f"Executing paginated GET for endpoint: {endpoint}") _next = endpoint results = [] while _next is not None: url = f'{self.cluster.base_url}{_next}' + logger.debug(f"Paginated GET request to {url}") response = self.execute_get_one(url) if response: next_page = response.get('next', None) results = response.get('results', response) + logger.debug(f"Next page: {next_page}") else: next_page = None if next_page: @@ -198,6 +217,7 @@ def execute_get(self, endpoint): @property def jobs(self): + logger.info("Fetching jobs for cluster.") parameters = "" if self.since is not None: since = self.since.isoformat().replace('+00:00', 'Z') @@ -206,27 +226,32 @@ def jobs(self): until = self.until.isoformat().replace('+00:00', 'Z') parameters += f'&finished__lte={until}' endpoint = f'{self.cluster.api_url}/jobs/?page_size=100&page=1&order_by=finished{parameters}' + logger.debug(f"Jobs endpoint: {endpoint}") response = self.execute_get(endpoint) for results in response: for result in results: + logger.debug(f"Yielding job: {result.get('id')}") yield result def job_host_summaries(self, job_id): + logger.info(f"Fetching host summaries for job {job_id}") endpoint = f'{self.cluster.api_url}/jobs/{job_id}/job_host_summaries?page_size=100&page=1&order_by=modified' response = self.execute_get(endpoint) for results in response: for result in results: + logger.debug(f"Yielding host summary: {result.get('id')}") yield result def sync_common(self, sync_type): + logger.info(f"Starting sync_common for type: {sync_type}") if sync_type == 'organization': endpoint = f'{self.cluster.api_url}/organizations/?page_size=100&page=1' qs = Organization.objects.filter(cluster=self.cluster) - elif sync_type == 'job_template': endpoint = f'{self.cluster.api_url}/job_templates/?page_size=200&page=1' qs = JobTemplate.objects.filter(cluster=self.cluster) else: + logger.error(f"Sync type {sync_type} not implemented.") raise NotImplementedError response = self.execute_get(endpoint) response_data = [] @@ -238,7 +263,7 @@ def sync_common(self, sync_type): for results in response: for result in results: db_item = db_data.pop(result["id"], None) - + logger.debug(f"Processing item: {result['id']}") if sync_type == 'job_template': external_organization = result.get("summary_fields", {}).get("organization", {}).get("id", None) if external_organization: @@ -249,12 +274,14 @@ def sync_common(self, sync_type): organization = None if db_item is not None: + logger.info(f"Updating {sync_type} {db_item.name}") db_item.name = result["name"] db_item.description = result["description"] if sync_type == 'job_template': db_item.organization = organization db_item.save() else: + logger.info(f"Creating new {sync_type} {result['name']}") if sync_type == 'job_template': JobTemplate.objects.create( cluster=self.cluster, @@ -281,70 +308,80 @@ def sync_common(self, sync_type): def ping(self, ping_url): logger.info(f'Pinging api {self.cluster.base_url}{ping_url}') url = f'{self.cluster.base_url}{ping_url}' - # Do same as execute_get_one(), but without authentication. - # ping is used to check version before token refresh, so we might not have a valid access token yet. - # ping endpoint does not required authentication, but (AAP 2.6 at least): - # - request is rejected if invalid HTTP basic auth is provided. - # - request is accepted if invalid 'Authorization: Bearer ...' is provided. timeout = 5 - response = requests.get( - url=url, - verify=self.cluster.verify_ssl, - timeout=timeout, - headers=self.headers) + try: + response = requests.get( + url=url, + verify=self.cluster.verify_ssl, + timeout=timeout, + headers=self.headers) + except requests.exceptions.RequestException as e: + logger.error(f"Ping request failed: {e}") + return None if response is None or not response.ok: + logger.warning(f"Ping to {url} failed or returned no response.") return None response = response.json() + logger.debug(f"Ping response: {response}") return response def detect_aap_version(self): logger.info(f'Checking if is AAP 2.5 ... 2.6 at {self.cluster.base_url}') response25 = self.ping("/api/gateway/v1/ping/") if response25: + logger.debug(f"AAP 2.5/2.6 ping response: {response25}") if response25["version"] == "2.6": return ClusterVersionChoices.AAP26 elif response25["version"] == "2.5": return ClusterVersionChoices.AAP25 else: + logger.error(f'Not valid version {response25["version"]} for cluster {self.cluster.base_url}.') raise Exception(f'Not valid version {response25["version"]} for cluster {self.cluster.base_url}.') logger.info(f'Checking if is AAP 2.4 at {self.cluster.base_url}') response24 = self.ping("/api/v2/ping/") if response24: + logger.debug(f"AAP 2.4 ping response: {response24}") return ClusterVersionChoices.AAP24 + logger.error(f'Not valid version for cluster {self.cluster.base_url}.') raise Exception(f'Not valid version for cluster {self.cluster.base_url}.') def check_aap_version(self): + logger.info("Checking AAP version for cluster.") aap_version = self.detect_aap_version() if self.cluster.aap_version != aap_version: + logger.info(f"Updating cluster version from {self.cluster.aap_version} to {aap_version}") self.cluster.aap_version = aap_version self.cluster.save() logger.info(f'Detected AAP version {aap_version} at {self.cluster.base_url}') return True def sync_jobs(self): + logger.info("Starting job sync.") for job in self.jobs: logger.info("Checking status of job %s", job) job_id = job.get("id", None) finished = job.get("finished", None) if job_id is None or finished is None: - logger.warning(f"Missing id or finished date time in job: {job}", ) + logger.warning(f"Missing id or finished date time in job: {job}") continue try: finished = datetime.datetime.fromisoformat(finished).astimezone(datetime.timezone.utc) except ValueError: + logger.error(f"Invalid finished date format for job: {finished}") raise TypeError(f"finished must be of type datetime.datetime job: {finished}") job["host_summaries"] = [] - logger.info(f"Job {job_id} retrieving host summaries.") for host_summary in self.job_host_summaries(job_id): + logger.debug(f"Appending host summary for job {job_id}: {host_summary.get('id')}") job["host_summaries"].append(host_summary) - with (transaction.atomic()): + with transaction.atomic(): logger.info(f"Job {job_id} saving data.") self.cluster_sync_data.last_job_finished_date = finished if self.cluster_sync_data.last_job_finished_date is None or finished > self.cluster_sync_data.last_job_finished_date else self.cluster_sync_data.last_job_finished_date self.cluster_sync_data.save() ClusterSyncData.objects.create(cluster=self.cluster, data=job) + logger.debug(f"Job {job_id} data saved.") diff --git a/src/backend/apps/clusters/encryption.py b/src/backend/apps/clusters/encryption.py index 3de62b4d..9299de76 100644 --- a/src/backend/apps/clusters/encryption.py +++ b/src/backend/apps/clusters/encryption.py @@ -1,3 +1,4 @@ +import logging import base64 import hashlib @@ -6,6 +7,7 @@ from django.conf import settings from django.utils.encoding import smart_bytes, smart_str +logger = logging.getLogger("automation_dashboard.clusters.encryption") class Fernet256(Fernet): """Not techincally Fernet, but uses the base of the Fernet spec and uses AES-256-CBC @@ -24,24 +26,32 @@ def __init__(self, key: bytes | str): def get_encryption_key() -> bytes: + logger.debug("Generating encryption key from SECRET_KEY.") h = hashlib.sha512() h.update(smart_bytes(settings.SECRET_KEY)) - return base64.urlsafe_b64encode(h.digest()) + key = base64.urlsafe_b64encode(h.digest()) + logger.debug("Encryption key generated.") + return key def encrypt_value(value: str) -> bytes: + logger.info("Encrypting value.") key = get_encryption_key() f = Fernet256(key) value = smart_str(value) - return f.encrypt(smart_bytes(value)) + encrypted = f.encrypt(smart_bytes(value)) + logger.debug("Value encrypted.") + return encrypted def decrypt_value(value: bytes) -> str: + logger.info("Decrypting value.") key = get_encryption_key() f = Fernet256(key) if value == b'': - # In DB is stored b'' only for old objects, where DB migration populated the field value. + logger.warning("Empty value detected for decryption.") decrypted = b'' else: decrypted = f.decrypt(value) + logger.debug("Value decrypted.") return smart_str(decrypted) diff --git a/src/backend/apps/clusters/parser.py b/src/backend/apps/clusters/parser.py index 70f6390f..8eee2094 100644 --- a/src/backend/apps/clusters/parser.py +++ b/src/backend/apps/clusters/parser.py @@ -24,43 +24,49 @@ LabelModelSchema, LabelsSchema) -logger = logging.getLogger("automation-dashboard") +logger = logging.getLogger("automation_dashboard.clusters.parser") class DataParser: """ - DataParser is responsible for extracting and transforming external job data - from a ClusterSyncData instance. It provides properties and methods to - retrieve or create related model instances (such as Organization, JobTemplate, - Inventory, etc.) and to parse and persist job and host summary information - into the database. The class ensures data consistency and handles updates - or creation of related objects as needed. - """ + DataParser is responsible for extracting and transforming external job data + from a ClusterSyncData instance. It provides properties and methods to + retrieve or create related model instances (such as Organization, JobTemplate, + Inventory, etc.) and to parse and persist job and host summary information + into the database. The class ensures data consistency and handles updates + or creation of related objects as needed. + """ def __init__(self, data_id): + logger.info(f"Initializing DataParser for data_id: {data_id}") self.data = None self.cluster = None self.model = ClusterSyncData.objects.filter(pk=data_id).prefetch_related("cluster").first() if self.model: + logger.debug("ClusterSyncData model found.") self.data = ExternalJobSchema(**self.model.data) self.cluster = self.model.cluster else: - logger.error("No data found for data id: {}".format(data_id)) + logger.error(f"No data found for data id: {data_id}") @property def organization(self) -> Organization | None: + logger.info("Accessing organization property.") external_organization = self.data.summary_fields.organization if external_organization: + logger.debug(f"Parsing organization: {external_organization.name}") return Organization.create_or_update( cluster=self.cluster, external_id=external_organization.id, name=external_organization.name, description=external_organization.description, ) + logger.debug("No external organization found.") return None @property def job_template(self) -> JobTemplate: + logger.info("Accessing job_template property.") external_job_template = self.data.summary_fields.job_template job_template = JobTemplate.create_or_update( cluster=self.cluster, @@ -69,69 +75,85 @@ def job_template(self) -> JobTemplate: description=external_job_template.description if external_job_template else self.data.description, ) job_count = Job.objects.filter(job_template=job_template).count() - # If no jobs exist for this template, it's safe to calculate the manual execution time + logger.debug(f"Job count for template: {job_count}") if job_count == 0: logger.info("No jobs exist for this template. Calculating manual execution time.") elapsed = self.data.elapsed if elapsed is not None: - manual_execution_time = int(decimal.Decimal(elapsed / 60 * 2).quantize(decimal.Decimal(1), rounding=decimal.ROUND_UP)) + manual_execution_time = int( + decimal.Decimal(elapsed / 60 * 2).quantize(decimal.Decimal(1), rounding=decimal.ROUND_UP)) + logger.debug(f"Calculated manual execution time: {manual_execution_time}") if manual_execution_time < settings.DEFAULT_TIME_TAKEN_TO_MANUALLY_EXECUTE_MINUTES: manual_execution_time = settings.DEFAULT_TIME_TAKEN_TO_MANUALLY_EXECUTE_MINUTES if manual_execution_time > 1000000: manual_execution_time = 1000000 job_template.time_taken_manually_execute_minutes = manual_execution_time job_template.save(update_fields=['time_taken_manually_execute_minutes']) + logger.info("Manual execution time updated for job template.") return job_template @property def launched_by(self) -> AAPUser | None: + logger.info("Accessing launched_by property.") external_launched_by = self.data.launched_by if external_launched_by and external_launched_by.id: + logger.debug(f"Parsing launched_by: {external_launched_by.name}") return AAPUser.create_or_update( cluster=self.cluster, external_id=external_launched_by.id, name=external_launched_by.name, type=external_launched_by.type, ) + logger.debug("No external launched_by found.") return None @property def inventory(self) -> Inventory | None: + logger.info("Accessing inventory property.") external_inventory = self.data.summary_fields.inventory if external_inventory: + logger.debug(f"Parsing inventory: {external_inventory.name}") return Inventory.create_or_update( cluster=self.cluster, external_id=external_inventory.id, name=external_inventory.name, description=external_inventory.description, ) + logger.debug("No external inventory found.") return None @property def execution_environment(self) -> ExecutionEnvironment | None: + logger.info("Accessing execution_environment property.") external_execution_environment = self.data.summary_fields.execution_environment if external_execution_environment is not None: + logger.debug(f"Parsing execution_environment: {external_execution_environment.name}") return ExecutionEnvironment.create_or_update( cluster=self.cluster, external_id=external_execution_environment.id, name=external_execution_environment.name, description=external_execution_environment.description, ) + logger.debug("No external execution_environment found.") return None @property def instance_group(self) -> InstanceGroup | None: + logger.info("Accessing instance_group property.") external_instance_group = self.data.summary_fields.instance_group if external_instance_group is not None: + logger.debug(f"Parsing instance_group: {external_instance_group.name}") return InstanceGroup.create_or_update( cluster=self.cluster, external_id=external_instance_group.id, name=external_instance_group.name, is_container_group=external_instance_group.is_container_group, ) + logger.debug("No external instance_group found.") return None def get_label(self, external_label: LabelModelSchema) -> Label: + logger.info(f"Getting label: {external_label.name}") return Label.create_or_update( cluster=self.cluster, external_id=external_label.id, @@ -143,17 +165,21 @@ def labels(self): logger.info("Getting labels.") external_labels = self.data.summary_fields.labels if external_labels is None or external_labels.count == 0: + logger.debug("No external labels found, using empty list.") external_labels = LabelsSchema(**{ "count": 0, "results": [] }) for label in external_labels.results: + logger.debug(f"Yielding label: {label.name}") yield self.get_label(label) @property def project(self) -> Project | None: + logger.info("Accessing project property.") external_project = self.data.summary_fields.project if external_project is not None: + logger.debug(f"Parsing project: {external_project.name}") return Project.create_or_update( cluster=self.cluster, external_id=external_project.id, @@ -161,9 +187,11 @@ def project(self) -> Project | None: description=external_project.description, scm_type=external_project.scm_type, ) + logger.debug("No external project found.") return None def get_host(self, host: NameDescriptionModelSchema | None, host_name: str) -> Host: + logger.info(f"Getting host: {host_name}") name = host.name if host else host_name description = host.description if host else "" external_id = host.id if host else -1 @@ -180,8 +208,10 @@ def host_summaries(self): logger.info("Getting host summaries.") external_host_summaries = self.data.host_summaries if not external_host_summaries: + logger.debug("No external host summaries found, using empty list.") external_host_summaries = [] for host_summary in external_host_summaries: + logger.debug(f"Processing host summary for host: {host_summary.host_name}") summary_fields = host_summary.summary_fields host = self.get_host(summary_fields.host, host_summary.host_name) data = host_summary.model_dump() @@ -191,13 +221,17 @@ def host_summaries(self): @property def job(self): + logger.info("Accessing job property.") data = self.data.model_dump() for key in ["summary_fields", "launched_by", "execution_environment", "host_summaries"]: data.pop(key, None) + logger.debug(f"Job data: {data}") return data def parse(self): + logger.info("Starting parse process.") if self.data is None: + logger.warning("No data to parse.") return organization = self.organization @@ -213,7 +247,7 @@ def parse(self): with transaction.atomic(): job = Job.objects.filter(cluster=self.cluster, external_id=external_id).first() if job is None: - logger.info("No job found, let's create new") + logger.info("No job found, creating new job.") job = Job.objects.create( cluster=self.cluster, external_id=external_id, @@ -227,7 +261,7 @@ def parse(self): **job_data ) else: - logger.info("Job already exists, updating.") + logger.info("Job already exists, updating job.") job.type = job_data.pop("type") job.job_type = job_data.pop("job_type") job.launch_type = job_data.pop("launch_type") @@ -246,18 +280,19 @@ def parse(self): logger.info("Job updated.") db_job_labels = {label.label_id: label for label in JobLabel.objects.filter(job=job)} + logger.debug(f"Existing job labels: {list(db_job_labels.keys())}") for label in self.labels: db_label = db_job_labels.pop(label.id, None) if db_label is None: - logger.info("Creating new job label.") + logger.info(f"Creating new job label for label id: {label.id}") JobLabel.objects.create(job=job, label=label) for key, value in db_job_labels.items(): - logger.info("Deleting old job label(s).") + logger.info(f"Deleting old job label with label id: {key}") value.delete() - logger.info("Deleting job host summary(s).") + logger.info("Deleting job host summaries.") JobHostSummary.objects.filter(job=job).delete() num_hosts = 0 @@ -286,7 +321,7 @@ def parse(self): logger.info("Creating new host summary.") JobHostSummary.objects.create(job=job, **host_summary) - logger.info("Processing summaries.") + logger.info("Processing job summary counts.") job.num_hosts = num_hosts job.changed_hosts_count = changed_hosts_count job.dark_hosts_count = dark_hosts_count @@ -298,7 +333,7 @@ def parse(self): job.ignored_hosts_count = ignored_hosts_count job.rescued_hosts_count = rescued_hosts_count - logger.info("Updating job with summaries.") + logger.info("Updating job with summary counts.") job.save() logger.info("Finished processing and deleting record.") diff --git a/src/backend/constants.py b/src/backend/constants.py new file mode 100644 index 00000000..f00e69d5 --- /dev/null +++ b/src/backend/constants.py @@ -0,0 +1,6 @@ +# loggers that may be called in process of emitting a log +LOGGER_BLOCKLIST = ( + 'automation_dashboard.utils.filters', + # dispatcherd should only use 1 database connection + 'dispatcherd', +) \ No newline at end of file diff --git a/src/backend/django_config/settings.py b/src/backend/django_config/settings.py index 50812337..fc66457d 100644 --- a/src/backend/django_config/settings.py +++ b/src/backend/django_config/settings.py @@ -51,6 +51,7 @@ 'django.contrib.staticfiles', 'django.contrib.humanize', 'django_generate_series', + 'django_guid', 'corsheaders', 'rest_framework', 'django_filters', @@ -70,6 +71,7 @@ MIDDLEWARE = [ + 'django_guid.middleware.guid_middleware', 'corsheaders.middleware.CorsMiddleware', 'django.middleware.security.SecurityMiddleware', 'django.contrib.sessions.middleware.SessionMiddleware', @@ -99,6 +101,8 @@ ROOT_URLCONF = 'django_config.urls' +DJANGO_GUID = {'GUID_HEADER_NAME': 'X-API-Request-Id'} + TEMPLATES = [ { 'BACKEND': 'django.template.backends.django.DjangoTemplates', @@ -141,48 +145,89 @@ 'PORT': DB_PORT, } } +LOG_AGGREGATOR_LEVEL = 'INFO' LOGGING = { "version": 1, "disable_existing_loggers": False, - 'formatters': { - 'verbose': { - 'format': '{levelname} {asctime} {module} {process:d} {thread:d} {message}', - 'style': '{', + "filters": { + "dynamic_level_filter": { + "()": "backend.utils.filters.DynamicLevelFilter", + }, + "guid": { + "()": "backend.utils.filters.DefaultCorrelationId", + }, + "require_debug_true_or_test": { + "()": "backend.utils.filters.RequireDebugTrueOrTest" }, + }, + 'formatters': { 'simple': { - 'format': '{levelname} {message}', - 'style': '{', + 'format': '%(asctime)s %(levelname)-8s [%(guid)s] %(name)s %(message)s' + }, + 'dispatcher': { + 'format': '%(asctime)s %(levelname)-8s [%(guid)s] %(name)s PID:%(process)d %(message)s' }, - 'dispatcher': {'format': '%(asctime)s %(levelname)-8s [%(guid)s] %(name)s PID:%(process)d %(message)s'}, }, "handlers": { "console": { - "class": "logging.StreamHandler", - "stream": sys.stdout, - "formatter": "verbose", + '()': 'logging.StreamHandler', + 'level': 'DEBUG', + 'filters': ['dynamic_level_filter', 'guid'], + 'formatter': 'simple', }, - }, - "root": { - "handlers": ["console"], - "formatter": "verbose", - "level": LOG_LEVEL, + 'file': {'class': 'logging.NullHandler', 'formatter': 'simple'}, }, "loggers": { 'django': {'handlers': ['console']}, - 'automation_dashboard.models': {'handlers': ['console']}, - 'automation_dashboard.consumers': {'handlers': ['console']}, - 'automation_dashboard.dispatch': {'handlers': ['console']}, - 'automation_dashboard.tasks': {'handlers': ['console']}, - 'automation_dashboard.tasks.jobs': {'handlers': ['console']}, - 'automation_dashboard.tasks.utils': {'handlers': ['console']}, - 'automation_dashboard.scheduler': {'handlers': ['console']}, - 'automation_dashboard.utils': {'handlers': ['console']}, - 'automation_dashboard.tasks.system': {'handlers': ['console']}, - 'automation_dashboard.analytics': {'handlers': ['console']} + 'django.request': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'WARNING'}, + 'ansible_base': {'handlers': ['console', 'file', 'automation_dashboard_warnings']}, + 'rest_framework.request': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'WARNING', 'propagate': False}, + 'dispatcherd': {'handlers': ['dispatcher', 'console'], 'level': 'INFO'}, + 'automation_dashboard': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'INFO'}, + 'automation_dashboard.auth': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'INFO'}, + 'automation_dashboard.jwt': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'INFO'}, + 'automation_dashboard.clusters.connector': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'INFO'}, + 'automation_dashboard.clusters.encryption': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'INFO'}, + 'automation_dashboard.clusters.parser': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'INFO'}, + 'automation_dashboard.aap_auth': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'INFO'}, + 'automation_dashboard.models': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'DEBUG'}, + 'automation_dashboard.consumers': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'INFO'}, + 'automation_dashboard.dispatch': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'INFO'}, + 'automation_dashboard.tasks': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'INFO'}, + 'automation_dashboard.tasks.jobs': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'INFO'}, + 'automation_dashboard.tasks.utils': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'DEBUG'}, + 'automation_dashboard.scheduler': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'DEBUG'}, + 'automation_dashboard.utils': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'DEBUG'}, + 'automation_dashboard.tasks.system': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'INFO'}, + 'automation_dashboard.analytics': {'handlers': ['console', 'file', 'automation_dashboard_warnings'], 'level': 'INFO'}, } } +handler_config = { + 'automation_dashboard_warnings': {'filename': 'automation_dashboard.log'}, + 'dispatcher': {'filename': 'dispatcher.log', 'formatter': 'dispatcher'}, +} +LOG_ROOT = "/var/log/automation_dashboard" +LOGGING_MODE = "stdout" # "stdout" or "file" + +for name, config in handler_config.items(): + LOGGING['handlers'][name] = { + "filters": ["dynamic_level_filter", "guid"], + "formatter": config.get('formatter', 'simple') + } + if LOGGING_MODE == 'file': + LOGGING['handlers'][name]['class'] = 'logging.handlers.WatchedFileHandler' + LOGGING['handlers'][name]['filename'] = os.path.join(LOG_ROOT, config['filename']) + + if LOGGING_MODE == 'stdout': + LOGGING['handlers'][name]['class'] = 'logging.NullHandler' + + +# Prevents logging to stdout on traditional VM installs +if LOGGING_MODE == 'file': + LOGGING['handlers']['console']['filters'].insert(0, 'require_debug_true_or_test') + # Password validation # https://docs.djangoproject.com/en/4.2/ref/settings/#auth-password-validators diff --git a/src/backend/tests/settings_for_test.py b/src/backend/tests/settings_for_test.py index 81d4c7fb..679589b7 100644 --- a/src/backend/tests/settings_for_test.py +++ b/src/backend/tests/settings_for_test.py @@ -50,6 +50,8 @@ JWT_ACCESS_TOKEN_LIFETIME_SECONDS = 60 JWT_REFRESH_TOKEN_LIFETIME_SECONDS = 7200 +SECRET_KEY='test_secret_key_for_backend_tests' + AAP_AUTH_PROVIDER = { 'name': 'test_name', 'protocol': 'https', diff --git a/src/backend/utils/filters.py b/src/backend/utils/filters.py new file mode 100644 index 00000000..1824bc42 --- /dev/null +++ b/src/backend/utils/filters.py @@ -0,0 +1,50 @@ +import logging +from django.conf import settings +from django_guid.log_filters import CorrelationId +from django_guid import get_guid + +from backend.common_utils import is_testing +from backend.constants import LOGGER_BLOCKLIST + + +def record_is_blocked(record): + """Given a log record, return True if it is considered to be + blocked, return False if not + """ + for logger_name in LOGGER_BLOCKLIST: + if record.name.startswith(logger_name): + return True + return False + + +class DynamicLevelFilter(logging.Filter): + def filter(self, record): + """Filters out logs that have a level below the threshold defined + by the database setting LOG_AGGREGATOR_LEVEL + """ + if record_is_blocked(record): + # Fine to write denied loggers to file, apply default filtering level + cutoff_level = logging.WARNING + else: + try: + cutoff_level = logging._nameToLevel[settings.LOG_AGGREGATOR_LEVEL] + except Exception: + cutoff_level = logging.WARNING + + return bool(record.levelno >= cutoff_level) + + +class RequireDebugTrueOrTest(logging.Filter): + """ + Logging filter to output when in DEBUG mode or running tests. + """ + + def filter(self, record): + return settings.DEBUG or is_testing() + + +class DefaultCorrelationId(CorrelationId): + def filter(self, record): + guid = get_guid() or '-' + record.guid = guid + return True