Skip to content

Fix OnEventf argument forwarding in the composite log - #779

Open
Robin1987China wants to merge 1 commit into
quickfixgo:mainfrom
Robin1987China:fix/composite-oneventf-variadic-forward
Open

Robin1987China wants to merge 1 commit into
quickfixgo:mainfrom
Robin1987China:fix/composite-oneventf-variadic-forward

Conversation

@Robin1987China

Copy link
Copy Markdown

Wrapped logs receive malformed event messages from a composite log. compositeLog.OnEventf forwarded
its variadic arguments as a single []interface{} value instead of expanding them, so every format
verb in the format string was rendered against that one slice.

Before

log/composite with two wrapped logs, l.OnEventf("session %s seq %d", "FIX.4.4", 7):

expected: []string{"session FIX.4.4 seq 7"}
actual  : []string{"session [FIX.4.4 %!s(int=7)] seq %!d(MISSING)"}

Even a single argument is mangled (%s renders the slice itself):

expected: []string{"session FIX.4.4"}
actual  : []string{"session [FIX.4.4]"}

There is no error — the garbage is written to the log and only shows up on inspection.

Fix

One line in log/composite/composite_log.go:

-		log.OnEventf(format, a)
+		log.OnEventf(format, a...)

quickfix.Log.OnEventf is OnEventf(string, ...interface{}), so a was passed as one argument whose
dynamic type is a slice.

Affected paths

Any call that goes through a composite log. 29 OnEventf call sites pass arguments — in acceptor.go,
session.go, in_session.go, session_state.go, initiator.go, logon_state.go, latent_state.go,
not_session_time.go — and 13 of them pass two or more. OnIncoming / OnOutgoing / OnEvent are
non-variadic and are not affected; this is the only occurrence in the repository.

Test

TestCompositeLogOnEventfExpandsFormatArgs in log/composite/composite_log_test.go, with three subtests:

  • single string arg"session %s": shows even one argument was corrupted.
  • mixed args"session %s seq %d": the common case, and where %!d(MISSING) appears.
  • slice arg"tags %v count %d" with a []int: guards against a "join the args into a string and
    forward that" fix, which would corrupt the output for slice arguments.

Each asserts both wrapped logs receive the expanded result.

It is a standalone Test* function rather than a case in the existing CompositeLogTestSuite: that
suite SkipNow()s as a whole when MONGODB_TEST_CXN is unset, so a test added there would silently
never run without MongoDB. The new test has no external dependencies — no MongoDB, no SQL, no network,
no credentials.

Verification

  • go build ./... — clean
  • go test -run TestCompositeLogOnEventfExpandsFormatArgs -v ./log/composite/ — 3/3 PASS
  • go test -race ./log/composite/ — ok
  • gofmt -l . and gofmt -s -l . — no output
  • make vet — exit 0
  • make test-ci — all packages pass except log/mongo, which fails identically on the unmodified
    baseline
    (see below); log/composite passes
  • golangci-lint (v1.64.6, repo .golangci.yml, GOTOOLCHAIN=go1.23.12) — 0 issues, same as baseline

Repeating the test with the one line reverted turns all three subtests red again, so the fix is what
drives them.

What I could not verify

  • No MongoDB locally, so make test (it hardcodes MONGODB_TEST_CXN=mongodb://db:27017) was not run;
    I ran the CI job's command make test-ci instead. log/mongo fails there both with and without my
    change — without a connection string the suite skips, then panics on a nil dereference — which is
    already tracked by Test: resolve panic when MONGODB_TEST_CXN is not set #755. Not caused by, and not fixed by, this PR.
  • CI lints on Go 1.21; locally only go1.26.5 is available. The 0-issue lint result was obtained on
    1.23.12 (the version declared in go.mod), not on 1.21.
  • make lint does not work locally as written (the Makefile installs the binary into ./bin but calls
    bare golangci-lint); I did not touch it.
  • make accept was not run — it needs ruby, make generate and an echo server. This change does not
    touch parsing, protocol or generated code.
  • No end-to-end session against a real counterparty was observed. The evidence is the unit test plus
    the call sites listed above.

compositeLog.OnEventf passed the variadic arguments as a single
[]interface{} argument, so every wrapped log rendered the format verbs
against one slice value, producing output such as
"session [FIX.4.4 %!s(int=7)] seq %!d(MISSING)" instead of
"session FIX.4.4 seq 7".
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant