Skip to content

topaz_file_decision_logger never writes decisions, plugin factory's logger is always nil (regression in 0.33.13) #736

Description

@jmanteau

This bug arise from a regression test from a previous app. I use AI to help me write the detailled summary after bug hunting.

Bug description

Since v0.33.13, enabling the file decision logger has no effect: decisions are accepted by the plugin but silently discarded. The file logger implementation (topazd/authorizer/plugins/decisionlog/file) is never instantiated anywhere in the codebase, so DecisionLogsPlugin.logger is always nil and Log() returns early without writing anything.

To Reproduce

  1. Run topaz 0.33.14 (or 0.33.13) with an authorizer config enabling the file decision logger:

    opa:
      instance_id: "test"
      local_bundles:
        paths: ["/policies"]
        skip_verification: true
      config:
        plugins:
          topaz_file_decision_logger:
            enabled: true
            config:
              log_file_path: /data/decisions.log
              max_file_size_mb: 20
              max_file_count: 3
  2. Issue authorizer is requests that evaluate policies (I drove ~120 authorized requests through it via an e2e suite).

  3. Observe /data/decisions.log is never created or updated. Under 0.33.12 with the equivalent config (aserto_decision_log plugin plus top-level decision_logger: section) the same traffic produces log entries.

Expected behavior

Decisions are appended to the configured log file, as in <= 0.33.12.

Root cause

The plugin reorg in #708 (fe6ffe8, first released in v0.33.13) removed the wiring that constructed the logger and injected it into the plugin factory:

  • In v0.33.12, topazd/topaz_run.go called topazApp.GetDecisionLogger(cfg.DecisionLogger) (which called file.New(...) for type: file) and passed the result to topaz.NewRuntimeResolver(..., decisionlog)decisionlog_plugin.NewFactory(decisionLogger).

  • In v0.33.13+, GetDecisionLogger and the parameter are gone. topazd/app/topaz/runtime_resolver.go now registers the factory with no logger:

    // runtime_resolver.go:63 — NewFactory() takes no arguments,
    // so PluginFactory.logger is the zero value (nil) forever.
    runtime.WithPlugin(decisionlog_plugin.PluginName, decisionlog_plugin.NewFactory()),
  • factory.New() forwards that nil logger into every plugin instance:

    // factory.go — f.logger is never assigned anywhere in the codebase.
    func (f PluginFactory) New(m *plugins.Manager, config any) plugins.Plugin {
        cfg, ok := config.(*Config)
        if !ok {
            return &DecisionLogsPlugin{}
        }
    
        return newDecisionLogger(cfg, m, f.logger) // f.logger == nil
    }
  • and plugin.Log() treats a nil logger as "nothing to do":

    // plugin.go — silently drops every decision when logger is nil,
    // even though cfg.Enabled is true.
    func (plugin *DecisionLogsPlugin) Log(ctx context.Context, d *api.Decision) error {
        if !plugin.cfg.Enabled || plugin.logger == nil {
            return nil
        }
        ...
    }

Nothing in the repo calls file.New or nop.New anymore. Meanwhile the plugin's Config gained a FileLogger file.Config json:"config"`` field (parsed and validated by factory.Validate) that is never used to build a logger. The plugin also reports `StateOK` on `Start()`, so plugin health gives no hint that logging is dead.

Suggested fix

Since the plugin is now explicitly file-specific (topaz_file_decision_logger) and its config already carries the file.Config, the simplest fix is to construct the file logger inside the factory from the validated config, rather than re-introducing external injection. Sketch:

// topazd/authorizer/plugins/decisionlog/factory.go

type PluginFactory struct {
    // ctx and logger are needed to construct file/nop loggers lazily in New();
    // plugins.Factory.New receives neither, so they must be captured here.
    ctx    context.Context
    logger *zerolog.Logger
}

func NewFactory(ctx context.Context, logger *zerolog.Logger) PluginFactory {
    return PluginFactory{ctx: ctx, logger: logger}
}

func (f PluginFactory) New(m *plugins.Manager, config any) plugins.Plugin {
    cfg, ok := config.(*Config)
    if !ok {
        return &DecisionLogsPlugin{}
    }

    var dlog decisionlog.DecisionLogger

    if cfg.Enabled {
        // cfg.FileLogger is already parsed and validated by Validate();
        // file.New applies SetDefaults() for any unset fields.
        l, err := file.New(f.ctx, &cfg.FileLogger, f.logger)
        if err != nil {
            // Fall back to nop rather than failing runtime startup, but make
            // the misconfiguration visible instead of silently dropping decisions.
            f.logger.Error().Err(err).Msg("failed to create file decision logger")
            dlog, _ = nop.New(f.ctx, f.logger) // nop.New never returns an error
        } else {
            dlog = l
        }
    }

    return newDecisionLogger(cfg, m, dlog)
}

and at the registration site:

// topazd/app/topaz/runtime_resolver.go — ctx and logger are already
// in scope as NewRuntimeResolver parameters.
runtime.WithPlugin(decisionlog_plugin.PluginName, decisionlog_plugin.NewFactory(ctx, logger)),

Reconfigure should probably also rebuild the logger when the file config changes, and Stop should call logger.Shutdown() so buffered output is flushed.

Related cleanup / docs

  • The top-level decision_logger: config section (v0.33.12 style) is now silently ignored for logging, but pkg/config/loader.go (getDecisionLogPaths) still reads it for path resolution, and pkg/config/topaz_config.go still defines DecisionLogConfig. Either remove it or document the migration.
  • The plugin rename aserto_decision_logtopaz_file_decision_logger (also rm self logger and reorg plugin #708) makes pre-0.33.13 configs fail hard at startup with failed to create discovery plugin: plugin "aserto_decision_log" not registered. A release-note migration entry (old name/section → new plugin block) would save users some debugging; neither the v0.33.13 nor v0.33.14 changelog mentions the config break.

Environment

  • topaz 0.33.14 (topazd 0.33.14 g1189dc6 linux-arm64), container ghcr.io/aserto-dev/topaz:0.33.14
  • config schema version 2, local bundles, embedded directory
  • Verified working on 0.33.12, broken on 0.33.13 and 0.33.14 (wiring identical in both)

Metadata

Metadata

Assignees

Labels

bugSomething isn't working

Type

Fields

No fields configured for Bug.

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions