[flaky test] FastTimingTests.ConcurrentEventsCanGrowAndDump loses dump completion marker in logcat

[simonrozsival]

Summary

Xamarin.Android.Build.Tests.FastTimingTests.ConcurrentEventsCanGrowAndDump is flaky in the macOS MSBuildDeviceIntegration On Device lanes. It has triggered automatic retries—and sometimes gated otherwise unrelated builds—across main and numerous PRs.

The test was added by #12455 to exercise concurrent FastTiming storage growth past the original 4,096-entry boundary and verify that the resulting timing data can be dumped completely.

Introduction and frequency

The test was introduced in commit bd7c9df5, merged through #12455 on August 20, 2026 at 13:58 UTC.

The first observed automatic retry was build #1560836, which started at 15:24 UTC—1 hour 26 minutes after the test merged.

Between August 20 and August 24, the test triggered automatic retries in at least 29 builds, including main and unrelated PRs.

Examples:

Build	Branch	Result
#1560836	PR #12459	Failed
#1560895	PR #12310	Succeeded after retry
#1561376	PR #12127	Failed
#1562070	PR #12114	Failed
#1562091	PR #12116	Failed
#1563855	main	Failed
#1564196	PR #12482	Failed
#1564346	PR #12485	Failed
#1564408	main	Failed

Failure

The assertion is:

Output did not contain [2/8] Assembly decompression.

The test:

1. Performs concurrent JNIEnv.GetJniName() calls to generate more than 4,096 FastTiming events.
2. Confirms that the event buffer grew.
3. Broadcasts mono.android.app.DUMP_TIMING_DATA.
4. Monitors logcat for the final [2/8] Assembly decompression aggregate line.

In build #1562091, both the initial attempt and retry showed:

Allocated timing event buffer from 4096 to 8192
Allocated timing event buffer from 8192 to 12288
FAST_TIMING_EVENTS_COMPLETED
[2/2] Performance measurement results

The dump then emitted a large number of nearly identical [1/6] Typemap.managed_to_java records. Android inserted repeated chatty suppression records, and the captured output stopped before the aggregate section:

[2/4] Accumulated performance results
[2/5] Assembly load
[2/6] Java to Managed lookup
[2/7] Managed to Java lookup
[2/8] Assembly decompression

The initial attempt captured approximately 1,090 ManagedToJava records; the retry captured approximately 1,754. Neither captured the terminal marker. There was no native crash or application failure.

Suspected cause

The test validates native event-storage correctness through a transport that is not reliable for thousands of messages emitted in a burst. Android logcat/logd appears to throttle, suppress, or drop part of the verbose dump before the final aggregate marker is observable.

The differing number of captured records across attempts supports a transport/collection race rather than deterministic FastTiming storage corruption. The precise throttling or drop mechanism still needs confirmation.

Expected behavior

The regression should reliably verify that:

• concurrent events can grow the native storage past 4,096 entries;
• all completed events can be traversed safely;
• the dump reaches its aggregate/completion section.

It should not depend on logcat successfully transporting thousands of verbose per-event messages in one burst.

Possible fixes

• Dump to a file and inspect that file instead of using logcat as the source of truth.
• Add a summary-only or completion signal that does not follow thousands of verbose records.
• Reduce the number of emitted records while still crossing the first storage chunk boundary.
• Split storage-growth validation from logcat/broadcast integration coverage.
• Quarantine the test until its output transport is reliable.

Acceptance criteria

• Repeated device runs do not require automatic retry.
• The test still exercises concurrent FastTiming growth beyond 4,096 events.
• Dump completion is validated through a reliable mechanism.
• The test no longer gates unrelated PR or main builds.

Related issues

• [CoreCLR] FastTiming::start_event corrupts the heap when debug.mono.log=timing (Scudo "invalid chunk state when deallocating") #12437 tracked the native heap corruption fixed by [native] Fix concurrent FastTiming event storage #12455.
• [Investigation] Integrate FastTiming with standardized tracing and metrics #12458 is the broader FastTiming diagnostics investigation.
• Generating methods.txt appears to stop writing to disk and is truncated #9693 tracks truncated methods.txt output and is not specific to this test.

[simonrozsival]

Local reproduction

Reproduced locally using the exact synthetic merge commit from Azure build #1562046: 3c48d1cfe0edde7aeb665b11455e4ca0aad833fe. This was the merge tested for PR #12115, which is unrelated to FastTiming.

Environment:

• macOS 26.6 on Apple Silicon
• API 36 arm64 emulator (sdk_gphone64_arm64)
• Exact Azure merge revision and a freshly rebuilt local SDK/test assembly

Command:

./dotnet-local.sh test \
  bin/TestDebug/MSBuildDeviceIntegration/net10.0/MSBuildDeviceIntegration.dll \
  --filter "Name~ConcurrentEventsCanGrowAndDump"

In an independently captured 10-run sequential loop, 8 runs failed and 2 passed. Every failure had the same assertion as CI:

Output did not contain [2/8] Assembly decompression.
Expected: True
But was:  False

No source, test configuration, binary, or emulator changed between iterations. The same build alternating between pass and failure at an 80% observed failure rate strongly supports an intermittent dump/logcat transport race rather than deterministic FastTiming storage corruption.