Fix: remove DEV_ALWAYS init cost from profiling timestamps

[hw-native-sys-bot]

Summary

• First DEV_ALWAYS call on AICPU has ~50us initialization overhead that was inflating profiling measurements
• Capture timestamps in variables before work, print together after execution completes
• Move orch_stage_end capture before transition_requested_ store to avoid DEV_ALWAYS delaying the critical store
• Fix aicpu_build_graph log format (Thread=%d → Thread %d:) to match benchmark_rounds.sh parser

Both aicpu_build_graph (3 locations) and tensormap_and_ringbuffer (4 locations) are fixed.

Benchmark (tensormap_and_ringbuffer, device 10, 10 rounds trimmed avg)

Example	Before	After	Delta
alternating_matmul_add	1096.0 us	1078.6 us	-17.4 us (-1.6%)
benchmark_bgemm	860.5 us	813.2 us	-47.3 us (-5.5%)
paged_attention_unroll Case1	1473.0 us	1409.5 us	-63.5 us (-4.3%)
paged_attention_unroll Case2	805.8 us	723.3 us	-82.5 us (-10.2%)
batch_paged_attention	3740.3 us	3736.8 us	-3.5 us (-0.1%)

Short-latency examples show ~50-80us improvement consistent with removing the init overhead from the measured interval. Longer examples show negligible change as expected.

Testing

• Simulation tests pass (12/12)
• Hardware benchmark validates the fix

[gemini-code-assist]

Summary of Changes

Hello, I'm Gemini Code Assist¹! I'm currently reviewing this pull request and will post my feedback shortly. In the meantime, here's a summary to help you and other reviewers quickly get up to speed!

This pull request significantly enhances the accuracy of performance profiling within the AICPU runtime by addressing an issue where an initial DEV_ALWAYS call introduced an artificial overhead into measurements. The core solution involves reordering how timestamps are captured and logged, ensuring that the profiling data truly reflects the execution time of operations. Additionally, log message formats have been standardized for improved parsing and consistency. These targeted adjustments result in more precise performance metrics and demonstrate tangible speedups, particularly for short-latency workloads.

Highlights

• Profiling Accuracy Improvement: Eliminated approximately 50us of initialization overhead from DEV_ALWAYS calls, which was previously inflating AICPU profiling measurements.
• Timestamp Capture Reordering: Reordered timestamp capture and logging logic to ensure timestamps are recorded in variables before the profiled work begins and printed after execution, leading to more accurate measurements.
• Critical Store Timing Correction: Adjusted the orch_stage_end timestamp capture to occur before the transition_requested_ atomic store, preventing DEV_ALWAYS overhead from delaying this critical operation.
• Log Format Standardization: Standardized the log message format for aicpu_build_graph from Thread=%d to Thread %d: to ensure consistency and compatibility with the benchmark_rounds.sh parser.
• Performance Validation: Validated the changes with hardware benchmarks, demonstrating significant performance improvements of up to 10.2% for short-latency examples, consistent with the removal of initialization overhead.

Using Gemini Code Assist

The full guide for Gemini Code Assist can be found on our documentation page, here are some quick tips.

Invoking Gemini

You can request assistance from Gemini at any point by creating a comment using either /gemini <command> or @gemini-code-assist <command>. Below is a summary of the supported commands on the current page.

Feature	Command	Description
Code Review	/gemini review	Performs a code review for the current pull request in its current state.
Pull Request Summary	/gemini summary	Provides a summary of the current pull request in its current state.
Comment	@gemini-code-assist	Responds in comments when explicitly tagged, both in pull request comments and review comments.
Help	/gemini help	Displays a list of available commands.

Customization

To customize Gemini Code Assist for GitHub experience, repository maintainers can create a configuration file and/or provide a custom code review style guide (such as PEP-8 for Python) by creating and adding files to a .gemini/ folder in the base of the repository. Detailed instructions can be found here.

Limitations & Feedback

Gemini Code Assist may make mistakes. Please leave feedback on any instances where its feedback is incorrect or counter productive. You can react with 👍 and 👎 on @gemini-code-assist comments. If you're interested in giving your feedback about your experience with Gemini Code Assist for GitHub and other Google products, sign up here.

Footnotes

1. Review the Privacy Notices, Generative AI Prohibited Use Policy, Terms of Service, and learn how to configure Gemini Code Assist in GitHub here. Gemini can make mistakes, so double check it and use code with caution. ↩

[gemini-code-assist]

Code Review

This pull request effectively addresses an issue where logging overhead was skewing profiling measurements. The changes correctly refactor the code to capture timestamps before work and log them after, which will lead to more accurate profiling. Moving a logging call after a critical store operation is also a good improvement to reduce latency. The standardization of log formats is a welcome addition for consistency and easier parsing. The changes are well-implemented and consistent across the modified files.