Skip to content

test: Fix test failures when session tracking is enabled#1393

Merged
vaind merged 6 commits intomasterfrom
fix/logs-test-failures-with-sessions
Oct 1, 2025
Merged

test: Fix test failures when session tracking is enabled#1393
vaind merged 6 commits intomasterfrom
fix/logs-test-failures-with-sessions

Conversation

@vaind
Copy link
Copy Markdown
Contributor

@vaind vaind commented Sep 29, 2025

Problem

Three unit tests in test_logs.c were failing due to:

  1. Session envelopes interfering with log envelope validation
  2. Thread startup race - logs sent immediately after sentry_init() were lost
  3. batching_stop flag not reset between test runs

Solution

Envelope filtering: Updated test callback to only count log envelopes, skip sessions.

Thread state machine: Replaced boolean batching_stop with enum-based states (STOPPED/RUNNING). Thread now signals when ready, eliminating race conditions.

Test synchronization: Added sentry__logs_wait_for_thread_startup() helper under #ifdef SENTRY_UNITTEST for deterministic thread readiness. Zero production overhead.

Testing

  • CI works
  • manually tested within console repos

Note

Replaces boolean stop flag with a RUNNING/STARTING/STOPPED thread state and CAS-based transitions, updates startup/shutdown accordingly, adds a test-only startup wait helper, and adjusts tests to filter log envelopes and avoid races.

  • Logs batching thread:
    • Introduce sentry_logs_thread_state_t with states STOPPED/STARTING/RUNNING stored in g_logs_state.thread_state.
    • Startup sets STARTING; thread compare_swap to RUNNING; shutdown store(STOPPED), wake, join, and final flush; added exit debug.
    • Add sentry__atomic_compare_swap in src/sentry_sync.h for state transitions.
  • Unit tests:
    • Add sentry__logs_wait_for_thread_startup() (unit-test only) and use it to remove timing races.
    • Update transport callback to only count "log" envelope items; adjust expectations.

Written by Cursor Bugbot for commit f0f2f05. This will update automatically on new commits. Configure here.

vaind and others added 2 commits September 29, 2025 21:08
This commit fixes 3 test failures in test_logs.c that occur when
auto-session tracking is enabled (the default):
- basic_logging_functionality
- formatted_log_messages
- logs_disabled_by_default

Root causes and fixes:

1. validate_logs_envelope counted all envelopes but only validated logs
   - Session envelopes from sentry_close() were triggering assertions
   - Fixed by filtering: only count/validate log envelopes, skip others

2. formatted_log_messages didn't wait for batching thread to start
   - Added sleep_ms(20) after sentry_init() to match other tests

3. batching_stop flag wasn't reset between sentry_init() calls
   - Once set to 1 during shutdown, subsequent startups would fail
   - Fixed by resetting to 0 in sentry__logs_startup()

These issues were discovered in console SDK testing where session
tracking is enabled by default and tests run sequentially in a single
process.

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: Claude <noreply@anthropic.com>
This commit eliminates the thread startup race condition by:

1. Replacing batching_stop with enum-based thread_state
   - SENTRY_LOGS_THREAD_STOPPED (0): Not running
   - SENTRY_LOGS_THREAD_RUNNING (1): Thread active and processing logs
   - Improves code clarity and makes thread lifecycle explicit

2. Thread signals RUNNING state after initialization
   - Batching thread sets state to RUNNING after mutex setup
   - Provides deterministic indication that thread is ready

3. Adding test-only helper: sentry__logs_wait_for_thread_startup()
   - Polls thread_state until RUNNING (max 1 second)
   - Zero production overhead (only compiled with SENTRY_UNITTEST)
   - Tests explicitly wait for thread readiness instead of arbitrary sleeps

4. Updating shutdown to use atomic state transition
   - Atomically transitions from RUNNING to STOPPED
   - Detects double shutdown or never-started cases
   - Returns early if thread wasn't running

Benefits:
- Eliminates race where logs could be enqueued before thread starts
- Tests are deterministic (no arbitrary timing assumptions)
- Code is clearer with explicit state names
- No production overhead (test helper is ifdef'd out)

The one remaining sleep in basic_logging_functionality test is intentional
- it tests batch timing behavior (wait for buffer flush).

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: Claude <noreply@anthropic.com>
@vaind vaind force-pushed the fix/logs-test-failures-with-sessions branch from 1395f7c to ebe0453 Compare September 30, 2025 08:38
@vaind vaind changed the title fix(logs): Fix test failures when session tracking is enabled test: Fix test failures when session tracking is enabled Sep 30, 2025
vaind and others added 2 commits September 30, 2025 11:24
This commit fixes a race condition in the logs batching thread lifecycle
that caused valgrind to report 336 byte memory leaks in CI tests.

## Problem

When `sentry__logs_shutdown()` ran before the batching thread transitioned
from initial state to RUNNING, the two-state model couldn't distinguish
between "never started" and "starting but not yet running", causing
shutdown to skip joining the thread.

## Solution

1. Added three-state lifecycle enum:
   - STOPPED (0): Thread never started or shut down
   - STARTING (1): Thread spawned but not yet initialized
   - RUNNING (2): Thread active and processing logs

2. Added `sentry__atomic_compare_swap()` primitive for atomic state
   verification (cross-platform: Windows InterlockedCompareExchange,
   POSIX __atomic_compare_exchange_n)

3. Startup sets state to STARTING before spawning thread

4. Thread uses CAS to verify STARTING → RUNNING transition
   - If CAS fails (shutdown already set to STOPPED), exits cleanly
   - Guarantees thread only runs if it successfully transitioned

5. Shutdown always joins thread if old state != STOPPED

## Benefits

- Eliminates race condition where shutdown could miss a spawned thread
- Thread explicitly verifies state transition with CAS
- No memory leaks in any shutdown scenario
- All 212 unit tests pass
- All log integration tests pass

Fixes test failures:
- test_before_send_log
- test_before_send_log_discard

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: Claude <noreply@anthropic.com>
@vaind
Copy link
Copy Markdown
Contributor Author

vaind commented Sep 30, 2025

@sentry review

Comment thread src/sentry_sync.h
Comment thread src/sentry_logs.c
Comment thread src/sentry_logs.c
Comment thread src/sentry_sync.h
Comment thread src/sentry_logs.c
Addresses bot review feedback by adding documentation without changing behavior:

1. **CAS memory ordering**: Added comment explaining sequential consistency
   usage for thread state transitions and why it's appropriate for
   synchronization

2. **Condition variable cleanup**: Added note explaining that static storage
   condition variables don't require explicit cleanup on POSIX and Windows

3. **CAS function documentation**: Enhanced docstring to document memory
   ordering guarantees and note that ABA problem isn't a concern for simple
   integer state machines

4. **Shutdown race handling**: Added comment explaining how the atomic CAS
   in the thread prevents the race when shutdown occurs during STARTING state

All changes are documentation/comments only - no behavior changes.

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: Claude <noreply@anthropic.com>
@vaind vaind marked this pull request as ready for review September 30, 2025 12:13
Comment thread src/sentry_logs.c Outdated
Co-authored-by: JoshuaMoelans <60878493+JoshuaMoelans@users.noreply.github.com>
Copy link
Copy Markdown
Collaborator

@supervacuus supervacuus left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Very nice, thanks @vaind!

Copy link
Copy Markdown
Member

@JoshuaMoelans JoshuaMoelans left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

lgtm, thanks for finding & fixing this!

@vaind vaind merged commit f2eaa5e into master Oct 1, 2025
67 of 68 checks passed
@vaind vaind deleted the fix/logs-test-failures-with-sessions branch October 1, 2025 13:13
BernhardMarconato pushed a commit to elgatosf/sentry-native that referenced this pull request Apr 21, 2026
)

* fix(logs): Fix test failures when session tracking is enabled

This commit fixes 3 test failures in test_logs.c that occur when
auto-session tracking is enabled (the default):
- basic_logging_functionality
- formatted_log_messages
- logs_disabled_by_default

Root causes and fixes:

1. validate_logs_envelope counted all envelopes but only validated logs
   - Session envelopes from sentry_close() were triggering assertions
   - Fixed by filtering: only count/validate log envelopes, skip others

2. formatted_log_messages didn't wait for batching thread to start
   - Added sleep_ms(20) after sentry_init() to match other tests

3. batching_stop flag wasn't reset between sentry_init() calls
   - Once set to 1 during shutdown, subsequent startups would fail
   - Fixed by resetting to 0 in sentry__logs_startup()

These issues were discovered in console SDK testing where session
tracking is enabled by default and tests run sequentially in a single
process.

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: Claude <noreply@anthropic.com>

* fix(logs): Eliminate thread startup race with enum state machine

This commit eliminates the thread startup race condition by:

1. Replacing batching_stop with enum-based thread_state
   - SENTRY_LOGS_THREAD_STOPPED (0): Not running
   - SENTRY_LOGS_THREAD_RUNNING (1): Thread active and processing logs
   - Improves code clarity and makes thread lifecycle explicit

2. Thread signals RUNNING state after initialization
   - Batching thread sets state to RUNNING after mutex setup
   - Provides deterministic indication that thread is ready

3. Adding test-only helper: sentry__logs_wait_for_thread_startup()
   - Polls thread_state until RUNNING (max 1 second)
   - Zero production overhead (only compiled with SENTRY_UNITTEST)
   - Tests explicitly wait for thread readiness instead of arbitrary sleeps

4. Updating shutdown to use atomic state transition
   - Atomically transitions from RUNNING to STOPPED
   - Detects double shutdown or never-started cases
   - Returns early if thread wasn't running

Benefits:
- Eliminates race where logs could be enqueued before thread starts
- Tests are deterministic (no arbitrary timing assumptions)
- Code is clearer with explicit state names
- No production overhead (test helper is ifdef'd out)

The one remaining sleep in basic_logging_functionality test is intentional
- it tests batch timing behavior (wait for buffer flush).

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: Claude <noreply@anthropic.com>

* fix(logs): Fix thread lifecycle race condition causing memory leaks

This commit fixes a race condition in the logs batching thread lifecycle
that caused valgrind to report 336 byte memory leaks in CI tests.

## Problem

When `sentry__logs_shutdown()` ran before the batching thread transitioned
from initial state to RUNNING, the two-state model couldn't distinguish
between "never started" and "starting but not yet running", causing
shutdown to skip joining the thread.

## Solution

1. Added three-state lifecycle enum:
   - STOPPED (0): Thread never started or shut down
   - STARTING (1): Thread spawned but not yet initialized
   - RUNNING (2): Thread active and processing logs

2. Added `sentry__atomic_compare_swap()` primitive for atomic state
   verification (cross-platform: Windows InterlockedCompareExchange,
   POSIX __atomic_compare_exchange_n)

3. Startup sets state to STARTING before spawning thread

4. Thread uses CAS to verify STARTING → RUNNING transition
   - If CAS fails (shutdown already set to STOPPED), exits cleanly
   - Guarantees thread only runs if it successfully transitioned

5. Shutdown always joins thread if old state != STOPPED

## Benefits

- Eliminates race condition where shutdown could miss a spawned thread
- Thread explicitly verifies state transition with CAS
- No memory leaks in any shutdown scenario
- All 212 unit tests pass
- All log integration tests pass

Fixes test failures:
- test_before_send_log
- test_before_send_log_discard

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: Claude <noreply@anthropic.com>

* docs(logs): Address code review comments with clarifying documentation

Addresses bot review feedback by adding documentation without changing behavior:

1. **CAS memory ordering**: Added comment explaining sequential consistency
   usage for thread state transitions and why it's appropriate for
   synchronization

2. **Condition variable cleanup**: Added note explaining that static storage
   condition variables don't require explicit cleanup on POSIX and Windows

3. **CAS function documentation**: Enhanced docstring to document memory
   ordering guarantees and note that ABA problem isn't a concern for simple
   integer state machines

4. **Shutdown race handling**: Added comment explaining how the atomic CAS
   in the thread prevents the race when shutdown occurs during STARTING state

All changes are documentation/comments only - no behavior changes.

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: Claude <noreply@anthropic.com>

* Update src/sentry_logs.c

Co-authored-by: JoshuaMoelans <60878493+JoshuaMoelans@users.noreply.github.com>

---------

Co-authored-by: Claude <noreply@anthropic.com>
Co-authored-by: JoshuaMoelans <60878493+JoshuaMoelans@users.noreply.github.com>
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.

3 participants