Skip to content

test: capture loader logs, stop test port clashes - #251

Merged
catinspace-au merged 1 commit into
mainfrom
fix/test-tracing
Oct 12, 2026
Merged

catinspace-au merged 1 commit into
mainfrom
fix/test-tracing

Conversation

@catinspace-au

Copy link
Copy Markdown
Contributor

A failing integration test printed only the ClickHouse container's stderr. The orchestrator runs inside the test process and nothing installed a tracing subscriber.

  • tests/common/test_logging.rs installs a tracing-subscriber fmt layer with the test writer, once per process. TestInfrastructure::new calls it
  • default filter is warn,dfe_loader=debug,scalo=info and RUST_LOG replaces it
  • passing tests print nothing
  • tracing-subscriber is a dev-dependency, the 0.3.23 scalo already resolves
  • grpc_outage start() logs the error when the loader exits. It was thrown away
  • free_port() claims each port with a marker socket held until the process exits

The last two go together. Test processes started together have consecutive pids, so free_port() searched from consecutive ports and probed the same listener port free for two of them. The second loader failed to bind, nothing logged it, and its client pushed into the first loader's table. That fits two grpc_outage failures that showed together in one run: "rows landed twice: {0}" in a_dlq_refusing_past_the_hold_holds_only_the_rows_it_must_take and "the first record never landed" in a_push_is_answered_only_once_its_row_is_in_clickhouse. a_port_is_handed_out_once fails on the old allocator and passes on the new one.

Done when a failing integration test shows the loader's own log lines and no two test processes are handed the same port.

The integration tests run the orchestrator in the test process, but nothing installed a tracing subscriber, so a failing test printed only the ClickHouse container's stderr. TestInfrastructure::new now installs one that writes through the harness's capture. The loader logs at debug, scalo at info and everything else at warn, and RUST_LOG replaces that filter. Passing tests print nothing.

grpc_outage also logs the error when a loader exits, which start() used to discard, and free_port() claims each port it hands out with a marker socket held until the process exits. Probing alone left a port free for a test process started beside this one, and consecutive pids search from consecutive ports. Two loaders could be given one address. The second died on the bind with nothing logged, and its client pushed into the first loader's table.
@catinspace-au
catinspace-au merged commit f4194ce into main Oct 12, 2026
17 checks passed
@catinspace-au
catinspace-au deleted the fix/test-tracing branch October 12, 2026 08:31
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