Logging

This page describes where Abacá writes its logs, how to control log verbosity, what format log lines take, and the invariants that govern what Abacá will and will not emit. Understanding the logging behaviour matters for two reasons: first, structured INFO-level logs are the primary correlation surface for diagnosing failed or stuck jobs across the control plane and worker fleet; second, the no-secrets invariant — enforced by unit tests — means you must know what identifiers to search for (job IDs, worker IDs, Barbican hrefs) rather than expecting credentials or tokens to appear in log output.

Before working with Abacá logs:

• Abacá control-plane components (abaca-api and abaca-conductor) deployed as pods in the abaca OpenShift namespace on RHOSO 18 or later.
• oc CLI authenticated to the OpenShift cluster hosting the control plane, with at least view access to the abaca namespace.
• For worker VM logs: SSH access to the relevant worker VM, or a log-forwarding pipeline (Loki, Elastic, Splunk, or similar) already ingesting the worker's journal.
• Familiarity with oslo.config INI-style configuration files — log level and format are set in abaca.conf.

Abacá's logging behaviour is built into the service and requires no separate installation step. Log output is written to standard output by all components — abaca-api, abaca-conductor, and abaca-worker-agent — and collected by whatever log aggregation pipeline you attach to the OpenShift pods or the worker VM journal.

1. Verify that log output is reachable for the API pod:

oc -n abaca logs deployment/abaca-api --follow

2. Verify that log output is reachable for the conductor pod:

oc -n abaca logs deployment/abaca-conductor --follow

3. For worker VMs, retrieve logs via the systemd journal on the worker:

# SSH into the worker VM, then:
journalctl -u abaca-worker-agent --follow

4. Confirm structured JSON output is active (INFO level and above always emits JSON):

oc -n abaca logs deployment/abaca-conductor --tail=5 | python3 -m json.tool

If the last few lines parse as JSON, structured logging is functioning correctly. If you see plain text at INFO level, check that no oslo.config override has set use_json = false in your deployment's abaca.conf.

Abacá uses oslo.config for all log-related settings. Log options are set in abaca.conf under the relevant sections. There is no dedicated [logging] section; oslo.logging options appear in [DEFAULT].

Log level

Set the log level via the standard oslo.config debug flag in [DEFAULT]:

[DEFAULT]
debug = false

Why this matters: The no-secrets invariant (see Invariants below) is only tested against INFO-level output. Free-text DEBUG lines are not covered by that guarantee — keep DEBUG off in production.

Key structured-log fields

Every log line at INFO or above includes the following JSON keys where applicable to the operation being logged:

Not every key is present on every line — only those that are contextually known at the point of emission.

Log aggregation invariants

These invariants are non-negotiable and are enforced by unit tests on the RPC and subprocess paths:

• No secrets are ever logged. KOPIA_PASSWORD, AWS_* environment variables, Keystone tokens, and S3 credentials never appear in log output at any level. Only Barbican hrefs and resource UUIDs appear.
• Structured JSON at INFO and above. Every INFO-level (and higher) line emits valid JSON with the correlation keys listed above.
• Free-text DEBUG lines are not shipped to operators. DEBUG is off by default and should remain off in production deployments.

Worker-agent log configuration

The abaca-worker-agent process running inside worker VMs is configured via the [worker] section. There are no separate log-path options for the agent; it writes to stdout, which systemd captures into the journal.

Relevant [worker] options that affect the verbosity of progress events written during a job:

[worker]
progress_interval_seconds = 30

Conductor timing options that influence log verbosity

The conductor emits log lines at the boundaries of each interval below. Reducing intervals increases log volume.

[conductor]
scheduler_interval = 60
reconciliation_interval = 300
worker_heartbeat_interval_seconds = 10

Tailing live logs from the control plane

To watch all INFO-level output from the conductor in real time:

oc -n abaca logs deployment/abaca-conductor --follow

To watch the API service:

oc -n abaca logs deployment/abaca-api --follow

Filtering by job ID

Because every INFO-level line is structured JSON with a job_id field, you can filter efficiently with jq:

oc -n abaca logs deployment/abaca-conductor \
  | jq -c 'select(.job_id == "<your-job-uuid>")'

Replace <your-job-uuid> with the UUID returned by openstack share protection backup show or the API.

Filtering by worker

oc -n abaca logs deployment/abaca-conductor \
  | jq -c 'select(.worker_id == "<worker-uuid>")'

Filtering by project or domain

oc -n abaca logs deployment/abaca-conductor \
  | jq -c 'select(.domain_id == "<domain-uuid>")'

Reading worker VM logs

Worker VMs write to the systemd journal via abaca-worker-agent. SSH into the relevant worker VM and run:

journalctl -u abaca-worker-agent -n 200 --no-pager

To stream live:

journalctl -u abaca-worker-agent --follow

Correlating control-plane and worker logs

A single backup job produces log lines in both abaca-conductor (job state machine transitions) and abaca-worker-agent (Kopia invocations, mount operations, progress). Use the job_id field as the correlation key across both sources. If you have a centralised log aggregation pipeline (Loki, Elastic, Splunk), index on job_id and query across both sources simultaneously.

Enabling debug logging temporarily

Set debug = true in abaca.conf and restart the affected pod. Because the configuration is managed by oslo.config and the pods are managed by kustomize, apply the change via your kustomize overlay and trigger a rollout:

# Edit your kustomize overlay to set debug = true in the abaca.conf ConfigMap,
# then apply:
kustomize build deploy/rhoso | oc apply -f -

# Force the conductor pod to pick up the new config:
oc -n abaca rollout restart deployment/abaca-conductor

Warning: DEBUG output is not covered by the no-secrets invariant and may contain sensitive operational detail. Disable debug logging and restart the pod before returning to normal operations.

Pulling audit events for SIEM ingestion

Audit events (secret access, admin actions, enrollment acknowledgments, job state transitions) are written to the abaca_events database table and are queryable via the API. Your log collector should poll this endpoint to feed your SIEM:

openstack share protection --os-token <admin-token> \
  -- GET /v1/admin/events?since=<ISO8601-timestamp>

The event payload includes actor, kind, severity, domain_id, project_id, subject_id, subject_kind, and a payload JSON block. See the API reference for the full schema.

Example 1: Extract all ERROR-level lines from the conductor since the last hour

oc -n abaca logs deployment/abaca-conductor \
  --since=1h \
  | jq -c 'select(.levelname == "ERROR")'

Expected output (one JSON object per error line, e.g.):

{"levelname": "ERROR", "message": "Job entered error state", "job_id": "3f7a1c2e-...", "worker_id": "a9d0...", "domain_id": "b12f...", "project_id": "c34e...", "target_id": "d56b..."}

If no lines are returned, no errors occurred in that window.

Example 2: Follow a specific backup job through all state transitions

After requesting an on-demand backup, capture its job ID and stream conductor logs filtered to that job:

JOB_ID=$(openstack share protection backup create <share-id> -f value -c job_id)

oc -n abaca logs deployment/abaca-conductor --follow \
  | jq -c --arg j "$JOB_ID" 'select(.job_id == $j)'

Expected output (one line per state transition):

{"levelname": "INFO", "message": "Job state: queued -> provisioning_network", "job_id": "3f7a...", "worker_id": null, "domain_id": "b12f...", "project_id": "c34e...", "target_id": "d56b..."}
{"levelname": "INFO", "message": "Job state: provisioning_network -> provisioning_source", "job_id": "3f7a...", ...}
{"levelname": "INFO", "message": "Job state: transferring", "job_id": "3f7a...", "worker_id": "a9d0..."}
{"levelname": "INFO", "message": "Job state: available", "job_id": "3f7a...", "worker_id": "a9d0..."}

The job has completed successfully when you see "available". If you see "error", proceed to the troubleshooting section.

Example 3: View worker agent progress lines during a large transfer

On the worker VM:

journalctl -u abaca-worker-agent --follow \
  | grep -i progress

Expected output (one line per progress_interval_seconds, default 30 s):

Mar 15 10:42:30 worker-a9d0 abaca-worker-agent[1234]: {"levelname": "INFO", "message": "Kopia transfer progress", "job_id": "3f7a...", "bytes_transferred": 1073741824, "elapsed_seconds": 30}
Mar 15 10:43:00 worker-a9d0 abaca-worker-agent[1234]: {"levelname": "INFO", "message": "Kopia transfer progress", "job_id": "3f7a...", "bytes_transferred": 2147483648, "elapsed_seconds": 60}

Example 4: Pull recent audit events via the API

TOKEN=$(openstack token issue -f value -c id)
SINCE=$(date -u -d '1 hour ago' +%Y-%m-%dT%H:%M:%SZ)

curl -s -H "X-Auth-Token: $TOKEN" \
  "https://<abaca-api-endpoint>/v1/admin/events?since=${SINCE}" \
  | jq '.events[] | {occurred_at, actor, kind, severity, subject_kind, subject_id}'

Expected output:

{"occurred_at": "2025-03-15T10:30:00Z", "actor": "system", "kind": "worker_dead", "severity": "error", "subject_kind": "worker", "subject_id": "a9d0..."}
{"occurred_at": "2025-03-15T10:31:15Z", "actor": "system", "kind": "fleet_health_critical", "severity": "error", "subject_kind": "system", "subject_id": null}

Issue 1: Log lines are plain text, not JSON

Symptom: oc logs output contains human-readable plain-text lines at INFO level rather than JSON objects.

Likely cause: An oslo.config override in abaca.conf or an environment variable has disabled JSON formatting, or the pod is running with debug = true (which may mix formats depending on the oslo.log handler configured).

Fix:

1. Inspect your kustomize overlay's ConfigMap for abaca.conf and confirm no use_json = false or conflicting log_format override is set.
2. Confirm debug = false in [DEFAULT].
3. Apply the corrected config and restart: oc -n abaca rollout restart deployment/abaca-conductor.

Issue 2: No log output from the conductor pod

Symptom: oc -n abaca logs deployment/abaca-conductor returns nothing or the pod shows as CrashLoopBackOff.

Likely cause: The conductor failed to start — commonly due to a bad [database] connection string, inability to reach RabbitMQ, or a failed abaca-manage db_sync job.

Fix:

1. Check the db-sync Job for errors first: oc -n abaca logs job/abaca-db-sync.
2. Check pod events: oc -n abaca describe pod -l app=abaca-conductor.
3. Verify the [database] connection and RabbitMQ DSN in your abaca.conf ConfigMap are reachable from within the pod network.

Issue 3: Job ID is missing from log lines

Symptom: Some INFO-level JSON lines do not contain a job_id field, making correlation across sources difficult.

Likely cause: The log line was emitted outside the context of a specific job — for example, during scheduler sweeps, reconciliation sweeps, or worker heartbeat processing. These control-plane housekeeping lines are not associated with a single job.

Fix: This is expected behaviour. Filter on domain_id or worker_id instead to narrow down the context, then cross-reference with job-specific lines that do carry job_id.

Issue 4: Worker VM logs show no output from abaca-worker-agent

Symptom: journalctl -u abaca-worker-agent returns No journal files were found or the unit is listed as inactive.

Likely cause: The worker image was built without the abaca-worker-agent service enabled, or the worker VM booted from an outdated image that pre-dates the current deployment.

Fix:

1. Confirm the worker VM booted from the correct Glance image: check that the image has the abaca_worker_image=1 property set (openstack image show <image-id> -c properties).
2. If the image is stale, build and register a new worker image per deploy/rhoso/worker/20-worker-image.sh and rotate the fleet.
3. On the worker VM, check: systemctl status abaca-worker-agent — if the unit is unknown, the image build did not include the agent.

Issue 5: Secrets or credentials appear in log output

Symptom: A log line contains what appears to be an S3 access key, a Kopia password, or a Keystone token.

Likely cause: This should not happen in a correctly built release — the no-secrets invariant is enforced by unit tests. If you observe it, the binary may be a locally patched build that bypassed CI, or a third-party library is logging an exception that includes credentials in its stack trace.

Fix:

1. Do not forward or store the affected log line externally.
2. Rotate the exposed credential immediately: revoke the Barbican secret, re-enroll the target, and issue a new Keystone trust.
3. Report the exact log line (with credential redacted) to the Abacá maintainers as a security issue — include the component (abaca-api, abaca-conductor, or abaca-worker-agent), the log level, and the build version.

Issue 6: High log volume from reconciliation or heartbeat loops

Symptom: Log aggregation costs or storage are excessive; the majority of lines are repetitive reconciliation or heartbeat entries.

Likely cause: Default intervals for reconciliation_interval (300 s) and worker_heartbeat_interval_seconds (10 s) produce frequent log lines at scale, especially with large worker fleets.

Fix: Increase the relevant intervals in [conductor] in abaca.conf:

[conductor]
reconciliation_interval = 600
worker_heartbeat_interval_seconds = 30

Note that increasing worker_heartbeat_deadline_seconds proportionally if you raise worker_heartbeat_interval_seconds — the deadline must remain comfortably larger than the interval to avoid false dead-worker alerts:

[conductor]
worker_heartbeat_interval_seconds = 30
worker_heartbeat_deadline_seconds = 90

Apply the change and restart the conductor pod.