more logging
Some checks failed
Lint Checks / Run linter (pull_request) Failing after 36s
Deploy Test / Run deploy test suite (pull_request) Failing after 1m36s
K8s Deploy Test / Run deploy test suite on kind/k8s (pull_request) Failing after 1m37s
Webapp Test / Run webapp test suite (pull_request) Failing after 1m33s
Smoke Test / Run basic test suite (pull_request) Failing after 1m12s

This commit is contained in:
Thomas E Lackey 2024-08-14 15:15:16 -05:00
parent e04631b4d5
commit 47979d7e44

View File

@ -226,6 +226,7 @@ def command(ctx, kube_config, laconic_config, image_registry, deployment_parent_
request_id, discover, state_file, only_update_state, request_id, discover, state_file, only_update_state,
dns_suffix, fqdn_policy, record_namespace_dns, record_namespace_deployments, dry_run, dns_suffix, fqdn_policy, record_namespace_dns, record_namespace_deployments, dry_run,
include_tags, exclude_tags, force_rebuild, log_dir): include_tags, exclude_tags, force_rebuild, log_dir):
root_logger = TimedLogger(file=sys.stderr)
if request_id and discover: if request_id and discover:
print("Cannot specify both --request-id and --discover", file=sys.stderr) print("Cannot specify both --request-id and --discover", file=sys.stderr)
sys.exit(2) sys.exit(2)
@ -251,14 +252,16 @@ def command(ctx, kube_config, laconic_config, image_registry, deployment_parent_
include_tags = [tag.strip() for tag in include_tags.split(",") if tag] include_tags = [tag.strip() for tag in include_tags.split(",") if tag]
exclude_tags = [tag.strip() for tag in exclude_tags.split(",") if tag] exclude_tags = [tag.strip() for tag in exclude_tags.split(",") if tag]
laconic = LaconicRegistryClient(laconic_config) laconic = LaconicRegistryClient(laconic_config, log_file=sys.stderr)
# Find deployment requests. # Find deployment requests.
# single request # single request
if request_id: if request_id:
root_logger.log(f"Retrieving request {request_id}.")
requests = [laconic.get_record(request_id, require=True)] requests = [laconic.get_record(request_id, require=True)]
# all requests # all requests
elif discover: elif discover:
root_logger.log(f"Discovering deployment requests.")
requests = laconic.app_deployment_requests() requests = laconic.app_deployment_requests()
if only_update_state: if only_update_state:
@ -266,6 +269,7 @@ def command(ctx, kube_config, laconic_config, image_registry, deployment_parent_
dump_known_requests(state_file, requests) dump_known_requests(state_file, requests)
return return
root_logger.log(f"Loading known requests.")
previous_requests = load_known_requests(state_file) previous_requests = load_known_requests(state_file)
# Collapse related requests. # Collapse related requests.
@ -274,7 +278,8 @@ def command(ctx, kube_config, laconic_config, image_registry, deployment_parent_
requests_by_name = {} requests_by_name = {}
skipped_by_name = {} skipped_by_name = {}
for r in requests: for r in requests:
status = None root_logger.log(f"BEGIN: Examining request {r.id}.")
result = "DEPLOY"
try: try:
if r.id in previous_requests and previous_requests[r.id].get("status", "") != "RETRY": if r.id in previous_requests and previous_requests[r.id].get("status", "") != "RETRY":
print(f"Skipping request {r.id}, we've already seen it.") print(f"Skipping request {r.id}, we've already seen it.")
@ -282,37 +287,41 @@ def command(ctx, kube_config, laconic_config, image_registry, deployment_parent_
app = laconic.get_record(r.attributes.application) app = laconic.get_record(r.attributes.application)
if not app: if not app:
print(f"Skipping request {r.id}, cannot locate app.") result = "ERROR"
status = "SEEN" root_logger.log(f"Skipping request {r.id}, cannot locate app.")
continue continue
requested_name = r.attributes.dns requested_name = r.attributes.dns
if not requested_name: if not requested_name:
requested_name = generate_hostname_for_app(app) requested_name = generate_hostname_for_app(app)
print("Generating name %s for request %s." % (requested_name, r.id)) root_logger.log(("Generating name %s for request %s." % (requested_name, r.id))
if requested_name in skipped_by_name or requested_name in requests_by_name: if requested_name in skipped_by_name or requested_name in requests_by_name:
print("Ignoring request %s, it has been superseded." % r.id) root_logger.log("Ignoring request %s, it has been superseded." % r.id)
result = "SKIP"
continue continue
if skip_by_tag(r, include_tags, exclude_tags): if skip_by_tag(r, include_tags, exclude_tags):
print("Skipping request %s, filtered by tag (include %s, exclude %s, present %s)" % (r.id, root_logger.log("Skipping request %s, filtered by tag (include %s, exclude %s, present %s)" % (r.id,
include_tags, include_tags,
exclude_tags, exclude_tags,
r.attributes.tags)) r.attributes.tags))
skipped_by_name[requested_name] = r skipped_by_name[requested_name] = r
result = "SKIP"
continue continue
print("Found request %s to run application %s on %s." % (r.id, r.attributes.application, requested_name)) root_logger.log_file("Found pending request %s to run application %s on %s." % (r.id, r.attributes.application, requested_name))
requests_by_name[requested_name] = r requests_by_name[requested_name] = r
except Exception as e: except Exception as e:
print(f"ERROR examining request {r.id}: " + str(e)) result = "ERROR"
status = "ERROR" root_logger.log(f"ERROR examining request {r.id}: " + str(e))
finally: finally:
if status: root_logger.log(f"DONE Examining request {r.id} with result {result}.")
if result in ["ERROR"]:
dump_known_requests(state_file, [r], status) dump_known_requests(state_file, [r], status)
# Find deployments. # Find deployments.
root_logger.log(f"Discovering existing app deployments...")
deployments = laconic.app_deployments() deployments = laconic.app_deployments()
deployments_by_request = {} deployments_by_request = {}
for d in deployments: for d in deployments:
@ -320,6 +329,7 @@ def command(ctx, kube_config, laconic_config, image_registry, deployment_parent_
deployments_by_request[d.attributes.request] = d deployments_by_request[d.attributes.request] = d
# Find removal requests. # Find removal requests.
root_logger.log(f"Discovering deployment removal and cancellation requests...")
cancellation_requests = {} cancellation_requests = {}
removal_requests = laconic.app_deployment_removal_requests() removal_requests = laconic.app_deployment_removal_requests()
for r in removal_requests: for r in removal_requests:
@ -329,22 +339,21 @@ def command(ctx, kube_config, laconic_config, image_registry, deployment_parent_
requests_to_execute = [] requests_to_execute = []
for r in requests_by_name.values(): for r in requests_by_name.values():
if r.id in cancellation_requests and match_owner(cancellation_requests[r.id], r): if r.id in cancellation_requests and match_owner(cancellation_requests[r.id], r):
print(f"Found deployment cancellation request for {r.id} at {cancellation_requests[r.id].id}") root_logger.log(f"Found deployment cancellation request for {r.id} at {cancellation_requests[r.id].id}")
elif r.id in deployments_by_request: elif r.id in deployments_by_request:
print(f"Found satisfied request for {r.id} at {deployments_by_request[r.id].id}") root_logger.log(f"Found satisfied request for {r.id} at {deployments_by_request[r.id].id}")
else: else:
if r.id not in previous_requests: if r.id not in previous_requests:
print(f"Request {r.id} needs to processed.") root_logger.log(f"Request {r.id} needs to processed.")
requests_to_execute.append(r) requests_to_execute.append(r)
else: else:
print( root_logger.log(f"Skipping unsatisfied request {r.id} because we have seen it before.")
f"Skipping unsatisfied request {r.id} because we have seen it before."
)
print("Found %d unsatisfied request(s) to process." % len(requests_to_execute)) root_logger.log("Found %d unsatisfied request(s) to process." % len(requests_to_execute))
if not dry_run: if not dry_run:
for r in requests_to_execute: for r in requests_to_execute:
root_logger.log("DEPLOYING {r.id}: BEGIN")
dump_known_requests(state_file, [r], "DEPLOYING") dump_known_requests(state_file, [r], "DEPLOYING")
status = "ERROR" status = "ERROR"
run_log_file = None run_log_file = None
@ -356,7 +365,7 @@ def command(ctx, kube_config, laconic_config, image_registry, deployment_parent_
if not os.path.exists(run_log_dir): if not os.path.exists(run_log_dir):
os.mkdir(run_log_dir) os.mkdir(run_log_dir)
run_log_file_path = os.path.join(run_log_dir, f"{run_id}.log") run_log_file_path = os.path.join(run_log_dir, f"{run_id}.log")
print(f"Directing deployment logs to: {run_log_file_path}") root_logger.log(f"Directing deployment logs to: {run_log_file_path}")
run_log_file = open(run_log_file_path, "wt") run_log_file = open(run_log_file_path, "wt")
run_reg_client = LaconicRegistryClient(laconic_config, log_file=run_log_file) run_reg_client = LaconicRegistryClient(laconic_config, log_file=run_log_file)
@ -378,8 +387,10 @@ def command(ctx, kube_config, laconic_config, image_registry, deployment_parent_
) )
status = "DEPLOYED" status = "DEPLOYED"
except Exception as e: except Exception as e:
root_logger.log("ERROR {r.id}:" + str(e))
logger.log("ERROR: " + str(e)) logger.log("ERROR: " + str(e))
finally: finally:
root_logger.log("DEPLOYING {r.id}: END - {status}")
if logger: if logger:
logger.log(f"DONE with status {status}", show_step_time=False, show_total_time=True) logger.log(f"DONE with status {status}", show_step_time=False, show_total_time=True)
dump_known_requests(state_file, [r], status) dump_known_requests(state_file, [r], status)