Skip to content

refactor(sync-service): Convert Logger calls to use static strings with metadata#3969

Draft
alco wants to merge 14 commits intomainfrom
refactor/static-logger-strings
Draft

refactor(sync-service): Convert Logger calls to use static strings with metadata#3969
alco wants to merge 14 commits intomainfrom
refactor/static-logger-strings

Conversation

@alco
Copy link
Member

@alco alco commented Mar 6, 2026

Summary

  • Refactor all Logger calls in electric-telemetry and sync-service packages to use static strings with metadata attributes instead of string interpolation
  • This improves log structuring for better observability and integrates with OTEL log handlers that can extract metadata fields
  • Update config/runtime.exs with extended metadata list for default formatter and OTEL metadata_map entries
  • Update Lux tests and unit tests to match the new log format

Test plan

  • Run mix compile --warnings-as-errors - passes
  • Run Lux integration tests to verify log patterns are correctly matched
  • Verify dynamic parameters appear in logs with metadata format

🤖 Generated with Claude Code

…th metadata

Refactor all Logger calls in electric-telemetry and sync-service packages to
use static strings with metadata attributes instead of string interpolation.

This improves log structuring for better observability and integrates with
OTEL log handlers that can extract metadata fields.

Changes:
- Extract dynamic values from log messages into metadata attributes
- Update config/runtime.exs with extended metadata list for default formatter
- Add OTEL metadata_map entries for new attributes
- Update Lux tests to match new log format with metadata
- Update unit tests to check for static messages with metadata

Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
@alco alco added the claude label Mar 6, 2026
@codecov
Copy link

codecov bot commented Mar 6, 2026

❌ 1 Tests Failed:

Tests completed Failed Passed Skipped
2595 1 2594 1
View the top 2 failed test(s) by shortest run time
Elixir.Electric.Connection.ConnectionManagerTest::test status monitor backtracks the status when the canary goes down
Stack Traces | 0.0615s run time
6) test status monitor backtracks the status when the canary goes down (Electric.Connection.ConnectionManagerTest)
     .../electric/connection/manager_test.exs:187
     Assertion with == failed
     code:  assert status.shape == :starting
     left:  :up
     right: :starting
     stacktrace:
       .../electric/connection/manager_test.exs:205: (test)
Elixir.Electric.Shapes.ConsumerTest::test transaction handling with real storage duplicate txn fragment handling is idempotent
Stack Traces | 1.32s run time
20) test transaction handling with real storage duplicate txn fragment handling is idempotent (Electric.Shapes.ConsumerTest)
     .../electric/shapes/consumer_test.exs:679
     match (=) failed
     code:  assert [
              {Storage, :append_fragment_to_log!, [[{_, ~s'"public"."test_table"/"3"', :insert, _}], _]},
              {Storage, :append_fragment_to_log!, [[{_, ~s'"public"."test_table"/"4"', :insert, _}], _]}
            ] = Support.StorageTracer.collect_traced_calls()
     left:  [
              {Electric.ShapeCache.Storage, :append_fragment_to_log!,
               [[{_, "\"public\".\"test_table\"/\"3\"", :insert, _}], _]},
              {Electric.ShapeCache.Storage, :append_fragment_to_log!,
               [[{_, "\"public\".\"test_table\"/\"4\"", :insert, _}], _]}
            ]
     right: []
     stacktrace:
       .../electric/shapes/consumer_test.exs:758: (test)
View the full list of 3 ❄️ flaky test(s)
Elixir.ElectricTelemetry.CallHomeReporterTest::test StackTelemetry report data conforms to remote server schema

Flake rate in main: 50.00% (Passed 49 times, Failed 49 times)

Stack Traces | 0.0087s run time
1) test StackTelemetry report data conforms to remote server schema (ElectricTelemetry.CallHomeReporterTest)
     .../electric/telemetry/call_home_reporter_test.exs:122
     ** (exit) shutdown
Elixir.ElectricTelemetry.CallHomeReporterTest::test reports all expected info when started under ApplicationTelemetry

Flake rate in main: 47.42% (Passed 51 times, Failed 46 times)

Stack Traces | 0.0038s run time
2) test reports all expected info when started under ApplicationTelemetry (ElectricTelemetry.CallHomeReporterTest)
     .../electric/telemetry/call_home_reporter_test.exs:30
     ** (exit) shutdown
Elixir.ElectricTelemetry.CallHomeReporterTest::test reports all expected info when started under StackTelemetry

Flake rate in main: 46.39% (Passed 52 times, Failed 45 times)

Stack Traces | 0.0708s run time
3) test reports all expected info when started under StackTelemetry (ElectricTelemetry.CallHomeReporterTest)
     .../electric/telemetry/call_home_reporter_test.exs:77
     ** (exit) shutdown

To view more test analytics, go to the Test Analytics Dashboard
📋 Got 3 mins? Take this short survey to help us improve Test Analytics.

@blacksmith-sh
Copy link
Contributor

blacksmith-sh bot commented Mar 6, 2026

Found 1 test failure on Blacksmith runners:

Failure

Test View Logs
Elixir.Electric.Connection.ConnectionManagerTest/
test status monitor backtracks the status when the canary goes down
View Logs

Fix in Cursor

alco and others added 2 commits March 6, 2026 13:20
Fix test assertions that were checking for interpolated log messages.
Now check for static messages with metadata attributes.

Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
@claude
Copy link

claude bot commented Mar 6, 2026

LINE1
LINE2
LINE3

alco and others added 7 commits March 6, 2026 13:33
Update Lux test patterns to match Logger calls that now use metadata
attributes instead of string interpolation.

Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
- Update manual-table-publishing.lux for Failed to create snapshot pattern
- Update postgres-disconnection.lux for Database connection failed pattern
- Update tests to use simpler "Starting replication client" pattern

Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
Update Snapshot started pattern to match new metadata-based format.

Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
- Rename `msg:` to `unexpected_msg:` to avoid reserved key conflict
- Remove `state:` from logger metadata to prevent credential leakage

Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
The Lux test fail pattern matches "error" case-insensitively, which
causes false failures when error_message= appears in log metadata output.
Renaming to err_msg avoids this issue.

Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
- Remove `opts: opts` metadata from SchemaReconciler (exposes internal config)
- Guard eager `length/1` calls in consumer.ex hot paths with `Logger.enabled?(:debug)`
- Rename `lock_name:` to `slot_name:` for consistency in acquire_lock log
- Remove redundant `client_pid: self()` from api.ex (`:pid` already in global metadata)
- Add missing metadata keys to formatter and OTEL metadata_map in runtime.exs
- Remove unused `lock_name` from formatter metadata list and OTEL map
- Update Lux tests for lock_name -> slot_name rename

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
@netlify
Copy link

netlify bot commented Mar 9, 2026

Deploy Preview for electric-next ready!

Name Link
🔨 Latest commit f86404d
🔍 Latest deploy log https://app.netlify.com/projects/electric-next/deploys/69aea9610e127000080c7b2b
😎 Deploy Preview https://deploy-preview-3969--electric-next.netlify.app
📱 Preview on mobile
Toggle QR Code...

QR Code

Use your smartphone camera to open QR code link.

To edit notification comments on pull requests, go to your Netlify project configuration.

@netlify
Copy link

netlify bot commented Mar 9, 2026

Deploy Preview for electric-next ready!

Name Link
🔨 Latest commit 7ff36e9
🔍 Latest deploy log https://app.netlify.com/projects/electric-next/deploys/69aea996a4836400089cac8f
😎 Deploy Preview https://deploy-preview-3969--electric-next.netlify.app
📱 Preview on mobile
Toggle QR Code...

QR Code

Use your smartphone camera to open QR code link.

To edit notification comments on pull requests, go to your Netlify project configuration.

@claude
Copy link

claude bot commented Mar 9, 2026

Claude Code Review

Summary

All five Important issues and the changeset suggestion from previous iterations have been resolved. The PR is in excellent shape — every Logger call in electric-telemetry and sync-service now uses static strings with structured metadata, the runtime.exs formatter list and OTEL metadata_map are comprehensively updated, and pid: shadowing has been eliminated across all affected files.

What’s Working Well

  • All previous issues addressed in this iteration — impressive cleanup pass.
  • The runtime.exs formatter metadata list expanded from 3 keys to ~85 keys, covering all Logger calls in the PR.
  • OTEL metadata_map likewise expanded to match, with semantically meaningful keys (pg.lsn, connection.role, db.query_string, etc.).
  • pid: renamed consistently: connection_pid: in pool.ex, materializer_pid: in consumer.ex, monitored_pid: in system_monitor.ex.
  • dep_handle / dependency_handle inconsistency resolved — both sites now use dep_handle:.
  • Changeset file added covering both sync-service and electric-telemetry.

Issues Found

Critical (Must Fix)

None.

Important (Should Fix)

None.

Suggestions (Nice to Have)

1. :txn and :txn_fragment in formatter list but absent from OTEL metadata_map

File: packages/sync-service/config/runtime.exs

:txn and :txn_fragment appear in the :default_formatter metadata list but have no corresponding entry in the OTEL metadata_map. If omission is intentional (e.g. to avoid serialising large transaction structs into traces), a brief comment would clarify the intent.


2. Large struct values stored as debug metadata

File: packages/sync-service/lib/electric/shapes/consumer.ex

txn and txn_fragment are full Elixir structs that can contain thousands of rows under high load. With a structured/JSON formatter or a custom OTEL handler, the entire struct would be serialised into every log line. Since these are :debug level they will not fire in production by default, but if debug logging is ever enabled under load the log volume could be significant. Consider replacing with a summary (e.g. xid: txn.xid, change_count: txn.num_changes) for consistency with the other debug messages in the same file that already extract only the relevant fields.


Issue Conformance

No linked issue. PR description is accurate and up to date. No change from previous reviews.

Previous Review Status

Issue Status
1. ~26 metadata keys missing from formatter list Fixed
2. dep_handle vs dependency_handle inconsistency Fixed
3. pid: shadowing built-in :pid Fixed
4. 9 OTEL map entries missing Fixed (and then some)
5. CI test failures CI results in conversation are from 2026-03-06, prior to the most recent commits. Recommend verifying the latest CI run before merge.
Changeset file Added

Review iteration: 7 | 2026-03-09

alco and others added 4 commits March 9, 2026 12:44
- Fix test assertion: lock_name= -> slot_name= in replication_client_test
- Rename message: to pg_message: metadata key to avoid OTEL reserved field
- Add missing metadata keys to formatter list (version, instance_id, etc.)
- Add missing OTEL metadata_map entries (query_string, idle_time_s, etc.)

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
Logger.enabled?/1 takes a PID, not a log level. Use
Logger.compare_levels(Logger.level(), :debug) != :gt to correctly
check if debug logging is enabled before computing expensive metadata.

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
- Add ~26 missing metadata keys to formatter list and OTEL metadata_map
- Rename pid: to connection_pid:/materializer_pid:/monitored_pid: to
  avoid shadowing built-in :pid metadata
- Standardize dependency_handle -> dep_handle for consistency
- Add 9 missing OTEL metadata_map entries (interval_ms, trash_dir, etc.)
- Add patch changeset for sync-service and electric-telemetry

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant