Skip to content

Logging improvement #249

Description

@bettercallsaulj

Logging improvement

Summary

  1. Surfaces SSL transport failures at warning level.
  2. Demotes noisy filter registry startup logs from Info to Debug.
  3. Adds MCP and HTTP request/response flow tracing behind dedicated logging controls.

The goal is to make transport failures visible by default while keeping normal startup quiet, and to allow protocol-flow debugging without enabling all component debug logs.

SSL warning logs

SslTransportSocket::handleSslError() now logs the failure reason at warning level:

GOPHER_LOG_WARN("SSL error: {}", reason);

Before this change, SSL failures were mostly stored in failure_reason_ and reported through callbacks. That made TLS handshake/read failures quiet at normal log levels, which slowed down diagnosis of crashes and connection teardown issues.

Expected behavior after the commit:

  • TLS failures are visible at default warning-enabled logging.
  • The detailed failure reason is still retained in failure_reason_.
  • Error callbacks and state transitions continue to work as before.

Quieter filter registry startup

Filter registry initialization and registration logs were demoted from Info to Debug:

  • Filter registry initialized
  • registered filter factory logs
  • registered context filter factory logs
  • circuit breaker filter factory registration

Before this change, these logs could appear during static initialization or process startup and pollute stdout before a host application had a chance to set its preferred log level.

Expected behavior after the commit:

  • Default startup is quieter.
  • Registry diagnostics are still available when Debug logging is enabled.

MCP flow logger

The commit adds a dedicated MCP protocol-flow logger component:

#define GOPHER_LOG_FLOW_COMPONENT "mcp.flow"
#define GOPHER_LOG_FLOW_DEBUG(...) GOPHER_LOG_FLOW(Debug, __VA_ARGS__)
#define GOPHER_LOG_FLOW_INFO(...) GOPHER_LOG_FLOW(Info, __VA_ARGS__)

These logs trace the request/response flow users usually care about:

  • initialize
  • tools/list
  • tools/call
  • resources/list
  • resources/read
  • prompts/list
  • prompts/get
  • HTTP connect/request/response flow

The key design point is that these flow logs use the mcp.flow component, so they can be enabled independently of all other Debug logs.

Environment controls

GOPHER_LOG_LEVEL

LoggerRegistry now initializes the global log level from GOPHER_LOG_LEVEL when set.

Examples:

GOPHER_LOG_LEVEL=debug <command>
GOPHER_LOG_LEVEL=info <command>
GOPHER_LOG_LEVEL=warn <command>

This affects all logger components.

GOPHER_MCP_LOG_FLOW

GOPHER_MCP_LOG_FLOW enables only the MCP flow logger at Debug level, without raising the global level.

Accepted truthy values:

  • 1
  • true
  • on
  • yes
  • enabled
  • debug

Example:

GOPHER_MCP_LOG_FLOW=1 <command>

This is useful when debugging MCP request hangs or routing issues where full global debug output would be too noisy.

HTTP logging

src/http/http_async_client.cc now uses the http component for normal HTTP warnings and mcp.flow for flow tracing.

New warning-level logs include:

  • socket creation failure;
  • IO handle creation failure;
  • invalid transport factory type;
  • unparseable URL;
  • failed request startup;
  • request failure callback.

New flow logs include:

  • connection target and TLS status;
  • outbound HTTP method/path/body size/header summary;
  • inbound HTTP status/body size.

Sensitive headers are redacted before logging. Header values for authorization and API-key style names are not logged in full; only a masked suffix is shown.

MCP client logging

src/client/mcp_client.cc now emits flow logs around common MCP operations:

  • initialization start/success;
  • list/read resources;
  • list/call tools;
  • list/get prompts.

Tool-call arguments are truncated for log safety. Large payloads are capped with a marker showing the original byte length.

Failures still use the normal error logger, for example failed initialize, failed tools/list, and failed tools/call.

How to verify

Check quiet default startup

Run an MCP client/server without debug flags and confirm registry startup chatter does not appear at Info by default.

Check SSL warning visibility

Trigger a TLS failure, such as bad certificate verification or an invalid TLS endpoint, and confirm an SSL error: ... warning appears.

Check MCP flow-only tracing

Run with:

GOPHER_MCP_LOG_FLOW=1 <command>

Expected behavior:

  • MCP operation flow logs appear.
  • HTTP request/response flow logs appear.
  • unrelated component Debug logs remain quiet.

Check global debug logging

Run with:

GOPHER_LOG_LEVEL=debug <command>

Expected behavior:

  • Debug logging is enabled globally.
  • MCP flow logs also appear because they follow the global level unless overridden.

Regression checklist

When changing logging in this area:

  • SSL failures should remain visible at warning level.
  • Static initialization and filter registration should not log at Info by default.
  • MCP flow logs should stay under the mcp.flow component.
  • GOPHER_MCP_LOG_FLOW should not raise the global log level.
  • Sensitive HTTP headers must remain redacted.
  • Large tool arguments/results should stay truncated in logs.
  • Logging must not alter request dispatch, response routing, or transport lifecycle behavior.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions