diff --git a/ddtrace/internal/flare/_subscribers.py b/ddtrace/internal/flare/_subscribers.py index 29ea0bea658..d54f1446271 100644 --- a/ddtrace/internal/flare/_subscribers.py +++ b/ddtrace/internal/flare/_subscribers.py @@ -23,6 +23,7 @@ def __init__( flare: Flare, stale_flare_age: int = DEFAULT_STALE_FLARE_DURATION_MINS, ): + log.info("initializing tracer flare sub") super().__init__(data_connector, callback, "TracerFlareConfig") self.current_request_start: Optional[datetime] = None self.stale_tracer_flare_num_mins = stale_flare_age @@ -57,7 +58,13 @@ def _get_data_from_connector_and_exec(self): log.debug("No config items received from data connector") return + log.info("parsing metadata") + log.info(metadata) + log.info("") for md in metadata: + log.info("md:") + log.info(md) + log.info("") product_type = md.get("product_name") if product_type == "AGENT_CONFIG": # We will only process one tracer flare request at a time @@ -67,15 +74,23 @@ def _get_data_from_connector_and_exec(self): str(self.current_request_start), ) continue + log.info("preparing tracer flare") if _prepare_tracer_flare(self.flare, configs): + log.info("setting self.current_request_start") self.current_request_start = datetime.now() + log.info(self.current_request_start) + log.info("") elif product_type == "AGENT_TASK": # Possible edge case where we don't have an existing flare request # In this case we won't have anything to send, so we log and do nothing if self.current_request_start is None: log.warning("There is no tracer flare job to complete. Skipping new request.") continue + log.info("generating tracer flare") if _generate_tracer_flare(self.flare, configs): + log.info("completed generation, resetting current request start") self.current_request_start = None + log.info(self.current_request_start) + log.info("") else: - log.debug("Received unexpected product type for tracer flare: {}", product_type) + log.info("Received unexpected product type for tracer flare: {}", product_type) diff --git a/ddtrace/internal/flare/flare.py b/ddtrace/internal/flare/flare.py index b37d6e8e013..b7025617d9c 100644 --- a/ddtrace/internal/flare/flare.py +++ b/ddtrace/internal/flare/flare.py @@ -97,18 +97,23 @@ def send(self, flare_send_req: FlareSendRequest): Revert tracer flare configurations back to original state before sending the flare. """ - self.revert_configs() - # We only want the flare to be sent once, even if there are # multiple tracer instances lock_path = self.flare_dir / TRACER_FLARE_LOCK + log.info("lock_path") + log.info(lock_path) if not os.path.exists(lock_path): + log.info("found lock_path") try: + log.info("attempting to open lock file") open(lock_path, "w").close() except Exception as e: log.error("Failed to create %s file", lock_path) raise e try: + log.info("creating connection to url") + log.info(self.url) + log.info("") client = get_connection(self.url, timeout=self.timeout) headers, body = self._generate_payload(flare_send_req.__dict__) client.request("POST", TRACER_FLARE_ENDPOINT, body, headers) @@ -121,13 +126,16 @@ def send(self, flare_send_req: FlareSendRequest): response.reason, response.read().decode(), ) + log.info("non 200 response code when sending flare") raise TracerFlareSendError(msg) except Exception as e: log.error("Failed to send tracer flare to Zendesk ticket %s: %s", flare_send_req.case_id, e) raise e finally: + log.info("closing client") client.close() # Clean up files regardless of success/failure + log.info("cleaning up files") self.clean_up_files() def _generate_config_file(self, pid: int): diff --git a/ddtrace/internal/flare/handler.py b/ddtrace/internal/flare/handler.py index 75ddac35188..e85d8897c66 100644 --- a/ddtrace/internal/flare/handler.py +++ b/ddtrace/internal/flare/handler.py @@ -30,10 +30,14 @@ def __init__(self, callback: Callable, flare: Flare): def _handle_tracer_flare(flare: Flare, data: dict, cleanup: bool = False): if cleanup: + log.info("Cleaning up") flare.revert_configs() flare.clean_up_files() return + log.info("data in handle_tracer_flare") + log.info(data) + log.info("") if "config" not in data: log.warning("Unexpected tracer flare RC payload %r", data) return @@ -43,9 +47,13 @@ def _handle_tracer_flare(flare: Flare, data: dict, cleanup: bool = False): product_type = data.get("metadata", [{}])[0].get("product_name") configs = data.get("config", [{}]) + log.info("configs in handle_tracer") + log.info(configs) if product_type == "AGENT_CONFIG": + log.info("found AGENT CONFIG") _prepare_tracer_flare(flare, configs) elif product_type == "AGENT_TASK": + log.info("found AGENT TASK") _generate_tracer_flare(flare, configs) else: log.warning("Received unexpected tracer flare product type: %s", product_type) @@ -56,11 +64,18 @@ def _prepare_tracer_flare(flare: Flare, configs: List[dict]) -> bool: Update configurations to start sending tracer logs to a file to be sent in a flare later. """ + log.info("prepare_config") + log.info(configs) + log.info("") for c in configs: # AGENT_CONFIG is currently being used for multiple purposes # We only want to prepare for a tracer flare if the config name # starts with 'flare-log-level' + if not isinstance(c, dict): + log.info("c is not type dict: %s", str(type(c))) + continue if not c.get("name", "").startswith("flare-log-level"): + log.info("c task is not tracer flare") continue flare_log_level = c.get("config", {}).get("log_level").upper() @@ -74,11 +89,16 @@ def _generate_tracer_flare(flare: Flare, configs: List[Any]) -> bool: Revert tracer flare configurations back to original state before sending the flare. """ + log.info("generate_config:") + log.info(configs) + log.info("") for c in configs: # AGENT_TASK is currently being used for multiple purposes # We only want to generate the tracer flare if the task_type is # 'tracer_flare' - if type(c) != dict or c.get("task_type") != "tracer_flare": + if not isinstance(c, dict): + continue + if c.get("task_type") != "tracer_flare": continue args = c.get("args", {}) flare_request = FlareSendRequest(