Skip to content

LDM Logging Strategy

This document defines the official logging architecture for Liferay Docker Manager. It exists to prevent inconsistent use of output levels across the codebase and to ensure the CLI feels appropriately terse to end users while remaining fully debuggable for developers and CI pipelines.

Logging Tier Architecture

LDM uses four console output tiers and one silent file tier:

Tier Method Flag Icon Audience
Standard UI.success() UI.warning() UI.error() UI.info() UI.heading() (always) ✅ ⚠️ ❌ ℹ All users
Info UI.detail() --info / -i ℹ Power users, troubleshooting
Verbose UI.debug() --verbose / -v ⚙️ Developers, CI debug
Trace UI.trace() (always, file only) — Log analysis (~/.ldm/last-command.log) 
ldm run <project>            # Standard output only
ldm run <project> --info     # Standard + Info tier
ldm run <project> --verbose  # Standard + Info + Verbose

Rule: Every log call must be placed at the correct tier at the point of writing. Do not escalate to a higher tier for convenience — demote to the correct tier.

Method Reference

UI.info(msg) — Standard tier, always shown

Use for phase-level milestones that mark meaningful progress a user needs to track.

Use when:

  • A named phase is starting or completing
  • The user would be confused or alarmed if this line didn't appear
  • This represents a top-level action the user explicitly requested

Examples:

UI.info("Downloading LDM package: liferay-ai-commerce-accelerator.ldmp...")
UI.info("Triggering orchestrated database restore (postgresql)...")
UI.info(f"Starting {project_id} stack ({tag}, {db_mode}, {host_name})...")
UI.info("Generating SSL certificates for aica.local...")
UI.info("Waiting for Elasticsearch to become ready...")

Do NOT use for:

  • Sub-steps within a phase (use detail())
  • Docker container lifecycle ops (use detail())
  • Internal state reads/writes (use debug())
  • File-level operations unless directly user-visible (use detail())

UI.detail(msg) — Info tier, shown with --info

Use for sub-step operations within a phase that a power user may want to follow.

Use when:

  • This is a meaningful step inside a larger named phase
  • A developer or advanced user would want visibility into this step for troubleshooting
  • The step is expected and routine (not alarming)

Examples:

UI.detail("Scaffolding Docker environment for restore...")
UI.detail(f"Hydrating volume: {volume_name} from host")
UI.detail(f"Synchronising virtual host to {host_name}")
UI.detail(f"Reclaimed volume ownership across {n} directories")
UI.detail("Checking infrastructure stack (Traefik SSL Proxy)...")
UI.detail(f"Synced license from Common: {match.name}")
UI.detail("Scheduled automatic search reindex for next boot.")

Do NOT use for:

  • Top-level phase milestones (use info())
  • Raw Docker command output (use debug())
  • API response payloads (use debug())

UI.debug(msg) — Verbose tier, shown with --verbose

Use for developer-level internals that are needed to diagnose failures but produce noise for normal users.

Use when:

  • The content is a raw command, API payload, or internal state value
  • Only a developer or CI engineer debugging a failure would need this
  • The output would be meaningless to an end user

Examples:

UI.debug(f"Running: {' '.join(cmd)}")
UI.debug(f"docker inspect output: {result}")
UI.debug(f"Detected ports {ports} from {lcp_file.name}")
UI.debug(f"Tag cache hit: {cache_key}")
UI.debug(f"  Reclaiming: {path}")  # per-directory detail within a batch
UI.debug(f"API response: {response.status_code} {response.text[:200]}")

UI.success(msg) — Standard tier, always shown

Use for completed milestones that confirm a meaningful outcome to the user.

Use when:

  • A phase or major operation has completed successfully
  • The user needs positive confirmation that something worked

Examples:

UI.success("LDM package checksum verified successfully.")
UI.success("Snapshot integrity verified.")
UI.success("Database restored successfully.")
UI.success("Restore complete.")
UI.success(f"Liferay is ready  ({elapsed})")

Do NOT use for:

  • Sub-step completions within a phase (use detail())
  • Trivial internal state confirmations (use debug())

UI.warning(msg) — Standard tier, always shown

Use only for genuine user-actionable advisories where something unexpected occurred or the user may need to act.

Use when:

  • Something unexpected happened but execution can continue
  • The user may need to take action (e.g. check a setting, restart a service)
  • A best-practice violation was detected

Legitimate warning() uses:

UI.warning(f"Port conflict detected! Using {new_port} instead of {orig_port}.")
UI.warning("Version downgrade detected. A pre-upgrade backup has been created.")
UI.warning(f"SSL certificate for {host} is not trusted by the system keychain.")
UI.warning(
    f"Search restore timed out. Indices may be incomplete — run: ldm reindex {project_id}"
)
UI.warning(f"Stale project lock auto-recovered (PID {pid} no longer running).")
UI.warning("Using '.local' TLD — ensure mkcert is installed and trusted.")

Do NOT use for:

  • Expected, routine operations (use info() or detail())
  • Volume permission reclaims — these are expected Docker behaviour (use detail())
  • Container teardown during a reset — this is expected (use detail())

The warning icon carries emotional weight. Every warning() line tells the user "something may be wrong". Use it sparingly so genuine warnings are not ignored.

UI.error(msg) — Standard tier, stderr

Use when an operation failed but execution continues in a degraded state.

UI.error("Client extension deployment failed.", details=str(e), tip="Check: ldm logs")
UI.error("Elasticsearch failed to become ready in time.")

UI.die(msg, exit_code=1) — Standard tier, stderr, halts execution

Use when a failure is unrecoverable and execution must stop.

UI.die(
    "Database restore failed after all retries. Original data preserved.", exit_code=3
)
UI.die("Elasticsearch failed after 2 restart attempts.", exit_code=3)

UI.heading(msg) — Standard tier, section headers

Use for top-level command banners, not for phase progress. Phase progress uses UI.phase().

UI.heading("Starting Quickstart: AICA")  # top of a command

UI.phase(current, total, label) — Standard tier, phase progress

Use for multi-step command progress orientation. Only applicable to commands with 3+ distinct phases.

UI.phase(1, 5, "Downloading")
UI.phase(2, 5, "Restoring")
UI.phase(3, 5, "Configuring")

Decision Tree

When writing a new log call, apply this decision tree:

Is this a failure?
+-- Yes, unrecoverable          --> UI.die()
+-- Yes, execution can continue --> UI.error()
+-- No --> continue

Is this a genuine user-actionable advisory?
+-- Yes --> UI.warning()
+-- No --> continue

Is this a completed milestone or positive confirmation?
+-- Yes --> UI.success()
+-- No --> continue

Is this a top-level phase the user explicitly triggered?
+-- Yes --> UI.info()
+-- No --> continue

Is this a sub-step within a named phase?
+-- Yes --> UI.detail()
+-- No --> continue

Is this an internal state value, raw command, or API payload?
+-- Yes --> UI.debug()

Anti-Patterns

Do not use warning() for expected operations

# Wrong - routine Docker operation
UI.warning(f"Reclaiming volume permissions for {path}...")

# Right - batch summary at detail level
UI.detail(f"Reclaimed volume ownership across {n} directories")

Do not use info() for sub-steps

# Wrong - sub-step of restore phase
UI.info("Scaffolding Docker environment for restore...")

# Right
UI.detail("Scaffolding Docker environment for restore...")

Do not use info() for internal state dumps

# Wrong
UI.info(f"  {key}={value}")  # property dump

# Right
UI.debug(f"  {key}={value}")

Do not emit O(n) lines where n is unbounded

# Wrong - 1 line per directory
for path in paths:
    UI.warning(f"Reclaiming volume permissions for {path}...")

# Right - 1 summary line, per-item detail only in verbose
UI.detail(f"Reclaimed volume ownership across {len(paths)} directories")
for path in paths:
    UI.debug(f"  {path}")

Do not call trace() manually

UI.trace() is called automatically by UI._print(). All output goes to ~/.ldm/last-command.log regardless of level.

One narrow exception: facts that are never printed at all. A handful of call sites record something the console deliberately never shows, so UI._print() never runs and there is nothing for it to trace. These are not a loophole for demoting noisy output -- if a line has a console tier, put it on that tier and let _print() trace it.

The exception covers exactly:

  • CommandRunner.run in ldm_core/utils.py, which records [CMD], [EXIT n], [STDOUT] and [STDERR] for every command it runs. LDM-#1615 added the [EXIT n]/[STDERR] pair to the check=False failure branch: that branch returns None and used to discard result.stderr outright, so a trace log from a failed run was indistinguishable from one from a successful run, and docker's own explanation of a failure could not be recovered by anyone. See last_command_failure() for the in-process half of the same record.
  • cli.py's catch-all except Exception, which traces the traceback. The terminal gets the exception type and message; the full traceback belongs in the file, not in a user's console.

Phase Headers

Multi-step commands must use phase headers to give users orientation:

# handlers/workspace.py - quickstart
UI.phase(1, 5, "Downloading")
# ... download work ...

UI.phase(2, 5, "Restoring")
# ... restore work ...

Commands that do NOT need phase headers (single-purpose): ldm logs, ldm status, ldm config, ldm snapshots, ldm stop, ldm nuke

Completion Banners

Any command that involves a Liferay boot wait (_wait_for_ready) must emit a completion banner:

Liferay is ready  (3m 42s)

  https://aica.local
  /Users/peterrichards/ldm/aica

  Next:  ldm logs aica        View live logs
         ldm snapshot aica    Take a backup

In --non-interactive mode, emit a single structured line:

Liferay ready: https://aica.local  (3m 42s)

Reviewing Log Calls

When reviewing PRs, flag any log call that:

  1. Uses UI.warning() for an expected/routine operation
  2. Uses UI.info() for a sub-step that is not a top-level phase milestone
  3. Emits O(n) lines where n is unbounded (batching required)
  4. Uses UI.success() for a trivial internal confirmation
  5. Duplicates a message that was already emitted in the same command run
  6. Appears inside a tight loop without a batching guard

The Python logging module

The tiers above are LDM's own output. A handful of call sites — currently only ldm_core/pipelines/base.py — use Python's logging module instead, because they report on pipeline stage machinery rather than on anything a user asked for.

Those records go to the trace log, never to the console. UI.init_trace_log() installs _TraceLogHandler on the root logger, which formats each record — including exc_info tracebacks — and writes it via UI.trace().

Logger Level Where it lands
pipeline.* (LDM's own) DEBUG ~/.ldm/last-command.log
everything else (docker, urllib3, werkzeug) WARNING ~/.ldm/last-command.log
anything — never the console

Why this exists (LDM-#1669)

Before it, nothing connected logging to LDM at all. Records at DEBUG were discarded outright, and WARNING+ were handled by logging.lastResort — a bare stderr StreamHandler, fixed at WARNING, with no formatter and no way to switch it off.

That is why LDM-#1668 could print a full Python traceback over a controlled UI.die, and why no flag suppressed it: -v/--verbose sets UI.VERBOSE, which belongs to the tier system above and has nothing to do with the logging module.

Installing any handler retires lastResort, so attaching the bridge is what keeps logging output off the console — not a separate suppression step.

Rules

  • Prefer the UI.* tiers. They are the documented interface, and they reach the trace log anyway via UI._print(). Reach for logging only for machinery a user would never be shown.
  • Never raise a record above DEBUG to make it visible. It will not appear on the console regardless, and at WARNING+ it merely becomes noise in a shared file. If a user needs to see something, that is what UI.info() / UI.warning() are for.
  • Do not add a second logging destination. The trace log is truncated per invocation and already carries a header (timestamp, command line, platform, Python version). A parallel log would split the evidence needed to diagnose one run.

Last Updated: 2026-09-11 | Last Reviewed: 2026-09-11