Skip to content

[MOD-10622] Change time measurement method in FT.PROFILE#6574

Merged
lerman25 merged 53 commits intomasterfrom
omerL-change-time-measure-profile
Aug 12, 2025
Merged

[MOD-10622] Change time measurement method in FT.PROFILE#6574
lerman25 merged 53 commits intomasterfrom
omerL-change-time-measure-profile

Conversation

@lerman25
Copy link
Copy Markdown
Collaborator

@lerman25 lerman25 commented Jul 30, 2025

This PR introduces a new time measurement abstraction: rs_wall_clock.
It provides high-precision, wall-clock time using clock_gettime(CLOCK_MONOTONIC), in nanoseconds, with helper conversions to milliseconds. Unlike clock(), which measures CPU time and is unreliable in multi-threaded or asynchronous environments, rs_wall_clock offers consistent and accurate wall time measurement. The goal is to fully deprecate and remove clock() usage across the codebase.

The rs_wall_clock utility includes:

  • A struct for capturing timestamps: rs_wall_clock
  • Nanosecond and millisecond types: rs_wall_clock_ns_t, rs_wall_clock_ms_t
  • Helper functions: rs_wall_clock_init(), rs_wall_clock_elapsed_ns(), rs_wall_clock_now_ns(), and rs_wall_clock_convert_ns_to_ms().

As a first step, rs_wall_clock has been integrated into FT.PROFILE time measurement.
Avoiding touching timeout handling and other time-sensitive logic, to minimize risk of unintended behavioral changes.

Next Steps

  • Migrate remaining timespec-based code (e.g. timeout.h, GC timers) to use rs_wall_clock
  • Consider replacing all ad hoc time measurements with the unified rs_wall_clock API
  • Consider using CLOCK_MONOTONIC_COARSE in places where ms granulity is enough (stackoverflow thread)

@lerman25 lerman25 added enforce:coverage Run coverage flow even on draft pull request enforce:sanitize Run sanitizer flow even on draft pull request labels Jul 30, 2025
@CLAassistant
Copy link
Copy Markdown

CLAassistant commented Jul 30, 2025

CLA assistant check
All committers have signed the CLA.

@codecov
Copy link
Copy Markdown

codecov bot commented Jul 30, 2025

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 87.51%. Comparing base (926d220) to head (dbfd7f2).
⚠️ Report is 8 commits behind head on master.

Additional details and impacted files
@@            Coverage Diff             @@
##           master    #6574      +/-   ##
==========================================
- Coverage   87.57%   87.51%   -0.06%     
==========================================
  Files         278      281       +3     
  Lines       44606    44664      +58     
  Branches     7571     7615      +44     
==========================================
+ Hits        39064    39088      +24     
- Misses       5430     5458      +28     
- Partials      112      118       +6     
Flag Coverage Δ
flow 84.50% <100.00%> (-0.19%) ⬇️
unit 49.18% <23.72%> (+0.04%) ⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

@lerman25 lerman25 marked this pull request as ready for review July 30, 2025 15:31
GuyAv46
GuyAv46 previously approved these changes Aug 11, 2025
@lerman25 lerman25 requested a review from raz-mon August 11, 2025 10:21
raz-mon
raz-mon previously approved these changes Aug 11, 2025
Copy link
Copy Markdown
Collaborator

@raz-mon raz-mon left a comment

Choose a reason for hiding this comment

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

Nicely done
Some non-critical nitpicks

Comment thread src/rs_wall_clock.h
Comment on lines +30 to +32
static inline void rs_wall_clock_init(rs_wall_clock *clk) {
clock_gettime(CLOCK_MONOTONIC, clk);
}
Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Consider removing this function

Comment thread src/rs_wall_clock.h Outdated
return (rs_wall_clock_ns_t)now.tv_sec * NANOSEC_PER_SECOND + now.tv_nsec;
}

static inline double rs_wall_clock_convert_ns_to_ms_f(rs_wall_clock_ns_t ns) {
Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

f = float?
If so change to rs_wall_clock_convert_ns_to_ms_d?
I would add some more documentation to this file in general

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

Agree, done

Comment thread src/rs_wall_clock.h
return ns / MILLISEC_PER_SECOND;
}

// Undefine macros to avoid conflicts
Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Do we have any conflicts?
I don't see an issue with keeping them defined

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

I agree with Guy on this,
I see no other use for it besides in this file (I don't want conversion to be done "manually")
Maybe if we see a use for this in the broader refactor to use rs_wall_clock

@lerman25 lerman25 dismissed stale reviews from raz-mon and GuyAv46 via dbfd7f2 August 11, 2025 16:29
@lerman25 lerman25 enabled auto-merge August 11, 2025 16:35
@lerman25 lerman25 disabled auto-merge August 11, 2025 16:35
@lerman25 lerman25 enabled auto-merge August 11, 2025 16:48
@lerman25 lerman25 added this pull request to the merge queue Aug 11, 2025
@github-merge-queue github-merge-queue bot removed this pull request from the merge queue due to failed status checks Aug 11, 2025
@lerman25 lerman25 added this pull request to the merge queue Aug 12, 2025
Merged via the queue into master with commit f8b4bff Aug 12, 2025
29 checks passed
@lerman25 lerman25 deleted the omerL-change-time-measure-profile branch August 12, 2025 08:39
@redisearch-backport-pull-request
Copy link
Copy Markdown
Contributor

Backport failed for 2.8, because it was unable to cherry-pick the commit(s).

Please cherry-pick the changes locally and resolve any conflicts.

git fetch origin 2.8
git worktree add -d .worktree/backport-6574-to-2.8 origin/2.8
cd .worktree/backport-6574-to-2.8
git switch --create backport-6574-to-2.8
git cherry-pick -x f8b4bfff6666a358be2792eb45c304c317a0ac20

@redisearch-backport-pull-request
Copy link
Copy Markdown
Contributor

Backport failed for 2.6, because it was unable to cherry-pick the commit(s).

Please cherry-pick the changes locally and resolve any conflicts.

git fetch origin 2.6
git worktree add -d .worktree/backport-6574-to-2.6 origin/2.6
cd .worktree/backport-6574-to-2.6
git switch --create backport-6574-to-2.6
git cherry-pick -x f8b4bfff6666a358be2792eb45c304c317a0ac20

@redisearch-backport-pull-request
Copy link
Copy Markdown
Contributor

Backport failed for 2.10, because it was unable to cherry-pick the commit(s).

Please cherry-pick the changes locally and resolve any conflicts.

git fetch origin 2.10
git worktree add -d .worktree/backport-6574-to-2.10 origin/2.10
cd .worktree/backport-6574-to-2.10
git switch --create backport-6574-to-2.10
git cherry-pick -x f8b4bfff6666a358be2792eb45c304c317a0ac20

@redisearch-backport-pull-request
Copy link
Copy Markdown
Contributor

Backport failed for 8.2, because it was unable to cherry-pick the commit(s).

Please cherry-pick the changes locally and resolve any conflicts.

git fetch origin 8.2
git worktree add -d .worktree/backport-6574-to-8.2 origin/8.2
cd .worktree/backport-6574-to-8.2
git switch --create backport-6574-to-8.2
git cherry-pick -x f8b4bfff6666a358be2792eb45c304c317a0ac20

JoanFM pushed a commit that referenced this pull request Apr 13, 2026
* introduce profile_clock

* add now function to profile_clock

* remove const keyword

* Many changes

* Revert "Many changes"

This reverts commit e92f8c6.

* fix rp next timing

* change AREQ initClock to new profile_clock, this includes changing global stats field

* change searchRequestCtx initClock to profile_clock type

* Revert "change searchRequestCtx initClock to profile_clock type"

This reverts commit 0495c8b.

* revert TotalGlobalStats_CountQuery to use clock_t instead of profile_clock_ns, but convert profile_clock to clock_t

* total_query_execution_time

* fix AREQ profileTotalTime

* fix AREQ profileParseTime

* fix AREQ profilePipelineBuildTime

* rename profile_clock to rs_wall_clock

* change total index time to rs_wall_clock

* Change searchRequestCtx profileClock to rs_wall_clock, change PrintCoordProfile_ctx fields to rs_wall_clock

* rename time unit convert macro

* change ProfileIterator, ProfileIteratorCtx to use wall clock

* change QueryIterator, QueryProcessingCtx initTime to rs_wall_clock

* Change  QueryIterator, QueryProcessingCtx GILTime to rs_wall_clock

* Use idiomatic rs_wall_clock in Print total GIL time

* Change rpSafeLoaderNext_Accumulate  rpStartTime to rs_wall_clock

* use ns to ms convert function

* rs_wall_clock aligments

* complete merge with master

* delete index.c

* use rs_wall_clock in cursor.c

* Revert "use rs_wall_clock in cursor.c"

This reverts commit c70f82c.

* change req init time to use rs_wall_clock instead of clock

* create 2 different conversion functions

* fix rs_wall_clock_diff_ns

* Apply suggestions from code review

Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>

* fix wrong diff and optimize elapsed

* fix comments

* move convert to outside of CountQuery function

* fix time aggreagation

* fix: add extern "C" block for C++ compatibility

* undefine macros

* fix: correct GILTime accumulation in buildPipelineAndExecute function

* fix: reorder rs_wall_clock functions for clarity and maintainability

* fix: update profileParseTime calculation to use rs_wall_clock_diff_ns, saving clock call

* fix macro name

* spellcheck

* fix: rename profileInitClock to initClock for consistency across aggregate profiling

* comments alignment

* Asser end >  start

* change rs_wall_clock to typedef timespec

* change convert to ms function name, better documentation

---------

Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

backport 2.6 backport 2.8 backport 2.10 backport 8.2 enforce:coverage Run coverage flow even on draft pull request enforce:sanitize Run sanitizer flow even on draft pull request size:M size:XL

Projects

None yet

Development

Successfully merging this pull request may close these issues.

6 participants