Skip to content

Fix reference file logging to avoid logcat output - #12620

Merged
simonrozsival merged 3 commits into
mainfrom
simonrozsival-startup-gc-investigation
Sep 2, 2026
Merged

simonrozsival merged 3 commits into
mainfrom
simonrozsival-startup-gc-investigation

Conversation

@simonrozsival

Copy link
Copy Markdown
Member

Description

OSBridge::log_it() unconditionally wrote reference log lines to logcat even when gref=<file> or lref=<file> selected file output without the + logcat option. Large GC-bridge diagnostics consequently flooded logcat and caused messages to be dropped.

Only write the line to logcat when no file is available or logcat output was explicitly requested. File output remains unchanged. The shared CLR host source covers CoreCLR and NativeAOT.

Validation

  • Built src/native/native-clr.csproj for all configured Android ABIs.
  • Built src/native/native-nativeaot.csproj for all configured Android ABIs.
  • Validated on an arm64 Android emulator with gc,gref=<file>: reference traffic was written to the file, while logcat contained only the file-open diagnostic. All 780 weak-reference creations and promotions were preserved in the file.

Copilot AI lite review requested due to automatic review settings September 1, 2026 11:21

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Copilot review overview

🟢 Approval recommended

Review tier: Lite
Findings: 1 Low severity

New issues introduced by this change (1)
Severity Finding
Low severity src/​native/​clr/​host/​os-bridge.cc — 💡 suggestion — The comment about “skipping logcat when logging to file” is now misleading because…
What changed in this PR

This PR adjusts native CLR host reference logging to prevent GC bridge “gref/lref” traffic from flooding logcat when file-based reference logging is selected, while preserving existing file output behavior.

Changes:

  • Gate OSBridge::log_it() logcat writes so they occur only when no file is available (to == nullptr) or when logcat output was explicitly requested.
  • Keep file logging and stack-trace emission behavior intact for reference logging.
File Description
src/​native/​clr/​host/​os-bridge.cc Avoid unconditional logcat writes when reference logging is routed to a file unless logcat is explicitly enabled.

Comment thread src/native/clr/host/os-bridge.cc Outdated
@simonrozsival

Copy link
Copy Markdown
Member Author

/review

@github-actions

github-actions Bot commented Sep 1, 2026 •

Copy link
Copy Markdown
Contributor

✅ Android PR Reviewer completed successfully!

Warning

Firewall blocked 1 domain

The following domain was blocked by the firewall during workflow execution:

  • azcliprod.blob.core.windows.net

To allow these domains, add them to the network.allowed list in your workflow frontmatter:

network:
  allowed:
    - defaults
    - "azcliprod.blob.core.windows.net"

See Network Configuration for more information.

Generated by Android PR Reviewer for #12620

@github-actions github-actions Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

⚠️ Needs Changes

Findings: 0 errors · 0 warnings · 1 suggestion

The routing condition correctly preserves compact no-file logging, suppresses logcat for file-only reference logs, and retains explicit gref+/lref+ output. I left one inline suggestion for automated regression coverage.

CI build #1576487 is currently red: Windows > Build & Smoke Test failed while much of the matrix is still running. The Azure DevOps CLI was not authenticated in this environment, so I could not determine whether that failure is related; it needs to be triaged or cleared before merge.

Warning

Firewall blocked 1 domain

The following domain was blocked by the firewall during workflow execution:

  • azcliprod.blob.core.windows.net

To allow these domains, add them to the network.allowed list in your workflow frontmatter:

network:
  allowed:
    - defaults
    - "azcliprod.blob.core.windows.net"

See Network Configuration for more information.

Generated by Android PR Reviewer for #12620 · gpt56 · 105.9 AIC · ⌖ 15.7 AIC · ⊞ 25.7K
Comment /review to run again

Comment thread src/native/clr/host/os-bridge.cc Outdated

@jonathanpeppers jonathanpeppers left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Could the overall function be rewritten to be a bit clearer:

	if (to == nullptr || logcat_enabled) {
		log_writef (category, LogLevel::Info, "%.*s", static_cast<int>(line.length ()), line.data ());
	}

	// We skip logcat here when logging to file is enabled because _write_stack_trace will output to logcat as well, if enabled
	if (to == nullptr) {
		if (logcat_enabled) {
			_write_stack_trace (nullptr, from, category);
		}

		return;
	}

I'm confused what is going on, now there are multiple if blocks checking the same values.

@simonrozsival
simonrozsival enabled auto-merge (squash) September 2, 2026 13:51
@simonrozsival

Copy link
Copy Markdown
Member Author

@jonathanpeppers The checks route two different outputs, which is why both values appear more than once: should_log_message_to_logcat() decides whether the main reference line goes to logcat, while the to == nullptr branch decides whether the stack trace has a file destination. Within the no-file branch, logcat_enabled distinguishes compact gref-/lref- logging from full gref+/lref+ logging.

I extracted the first decision into a named constexpr predicate and added static_assert coverage for all four file/logcat combinations. I also clarified the nearby comment so it describes only the no-file stack-trace behavior.

@simonrozsival
simonrozsival merged commit 226e151 into main Sep 2, 2026
44 checks passed
@simonrozsival
simonrozsival deleted the simonrozsival-startup-gc-investigation branch September 2, 2026 19:38
simonrozsival added a commit that referenced this pull request Sep 18, 2026
----

`adb logcat -d` can stall even after `adb devices` reports a connected emulator. Azure Pipelines then applies the one-minute task timeout added by #12471, records an error, and converts the task to `SucceededWithIssues` because it uses `continueOnError`. The final `fail-on-issue.yaml` step intentionally turns that status into a job failure. This occurred in builds [1583273](https://dev.azure.com/dnceng-public/public/_build/results?buildId=1583273) and [1585745](https://dev.azure.com/dnceng-public/public/_build/results?buildId=1585745). The log-volume reduction in #12620 does not prevent adb or emulator communication from stalling.

Add a reusable PowerShell helper that bounds device discovery to 10 seconds and logcat collection to 45 seconds. It redirects logcat directly to the existing artifact path, preserving complete output on success and partial output on timeout, kills timed-out process trees with a bounded grace period, emits an explicit Azure warning, and exits successfully for capture-only failures.

The pipeline keeps `condition: always()` but no longer relies on task-level timeout or `continueOnError`, so diagnostic capture cannot change `Agent.JobStatus`. `fail-on-issue.yaml` remains unchanged and continues to gate unrelated build and test failures.

Related: #12704
Prior mitigations: #12471, #12620

- [x] Useful description of *why the change is necessary*.
- [x] Links to issues fixed
- [ ] Unit tests - N/A; the production helper runs in every APK instrumentation lane.
@github-actions github-actions Bot locked and limited conversation to collaborators Oct 3, 2026
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants