Skip to content

Commit c7c3d0e

Browse files
Simonclaude
andcommitted
Fix ecs_progress blocking when the clock does not advance between frames
Frame time measurement retried in a loop until the clock returned a nonzero delta. On a clock that is too coarse to measure a short frame (a browser with reduced timer precision, a coarse OS tick), every frame that finishes within one clock quantum busy-spins reading the clock until the quantum passes. On a clock that only advances when the host steps it in between frames (emscripten without asyncify, simulated clocks) the loop never exits and ecs_progress blocks forever. A zero measurement now reports a minimal nonzero delta (ECS_FRAME_MIN_DELTA_TIME) rather than measuring again until the clock moves. Because the frame start time is written back value-identical when the clock did not advance, the elapsed time is credited in full to the frame in which the clock next advances, so no time is lost or invented beyond the reported minimum. Reporting a nonzero delta also keeps every existing divisor of delta_time safe. A delta of zero is already observable today (time_scale 0, OnStart systems), so this changes no contract for consumers. The first frame that reports the minimum logs a warning, once per world, so a rate that was computed by dividing by it can be traced to the clock rather than debugged as a spike. The first-frame branch is now selected by a world flag instead of testing the frame start time against zero, which pinned a simulated clock that starts at 0 to the first-frame branch forever. The world summary computed fps as 1.0 / delta_time_raw, which is inf before the first measured frame (not representable in JSON on the REST endpoint) and a rate in the billions on frames where the clock did not advance. It now reports 0 when no measurable frame time exists, and the windowed fps gauge in the stats addon applies the same threshold: a stats window averaging at or below the minimum delta reports 0 instead of the reciprocal of the minimum. Tests cover a stalled clock, a stalled clock that reads 0, the warning firing exactly once across repeated stalled frames, and a coarse clock, including that measured deltas add up to how far the clock actually moved; the stalled clock stats test pins the summary and the gauge together. Note: with a target FPS configured a stalled clock still blocks, in the frame rate limiting loop of flecs_insert_sleep. That is a separate defect with its own fix and tests, submitted as a follow-up PR. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
1 parent e8c1334 commit c7c3d0e

16 files changed

Lines changed: 456 additions & 45 deletions

File tree

distr/flecs.c

Lines changed: 52 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -4133,6 +4133,13 @@ void flecs_wait_for_sync(
41334133
/* Used in id records to keep track of entities used with id flags */
41344134
extern const ecs_entity_t EcsFlag;
41354135

4136+
/* Smallest delta time reported for a frame. Reported instead of zero when the
4137+
* clock did not advance in between two measurements; consumers that derive a
4138+
* rate from the frame delta test against it to tell a stalled frame apart from
4139+
* a very short one. Rounds to zero (disabling both) if ecs_ftime_t is redefined
4140+
* to an integer or fixed point type. */
4141+
#define ECS_FRAME_MIN_DELTA_TIME ((ecs_ftime_t)1e-9)
4142+
41364143
////////////////////////////////////////////////////////////////////////////////
41374144
//// Bootstrap API
41384145
////////////////////////////////////////////////////////////////////////////////
@@ -24397,28 +24404,41 @@ static ecs_ftime_t flecs_start_measure_frame(
2439724404
(ECS_EQZERO(user_delta_time)))
2439824405
{
2439924406
ecs_time_t t = world->frame_start_time;
24400-
do {
24401-
if (world->frame_start_time.nanosec || world->frame_start_time.sec){
24402-
delta_time = flecs_insert_sleep(world, &t);
24403-
} else {
24404-
ecs_time_measure(&t);
24405-
if (ECS_NEQZERO(world->info.target_fps)) {
24406-
delta_time = (ecs_ftime_t)1.0 / world->info.target_fps;
24407-
} else {
24408-
/* Best guess */
24409-
delta_time = (ecs_ftime_t)1.0 / (ecs_ftime_t)60.0;
2441024407

24411-
if (ECS_EQZERO(delta_time)) {
24412-
delta_time = user_delta_time;
24413-
break;
24414-
}
24415-
}
24408+
/* A simulated clock can legitimately start at 0, so the frame start
24409+
* time itself can't tell whether a previous frame measured one. */
24410+
if (world->flags & EcsWorldFrameStartTimeSet) {
24411+
delta_time = flecs_insert_sleep(world, &t);
24412+
} else {
24413+
ecs_time_measure(&t);
24414+
if (ECS_NEQZERO(world->info.target_fps)) {
24415+
delta_time = (ecs_ftime_t)1.0 / world->info.target_fps;
24416+
} else {
24417+
/* Best guess */
24418+
delta_time = (ecs_ftime_t)1.0 / (ecs_ftime_t)60.0;
2441624419
}
24420+
}
2441724421

24418-
/* Keep trying while delta_time is zero */
24419-
} while (ECS_EQZERO(delta_time));
24422+
if (delta_time < ECS_FRAME_MIN_DELTA_TIME) {
24423+
/* A coarse or host-stepped clock can legitimately return the same
24424+
* instant twice. Report the smallest nonzero delta rather than
24425+
* measure again until the clock moves, which never returns on a
24426+
* host-stepped clock. The frame start time is unchanged, so the
24427+
* elapsed time is credited in full to the frame in which the
24428+
* clock next advances. */
24429+
delta_time = ECS_FRAME_MIN_DELTA_TIME;
24430+
24431+
/* Once per world, so a rate computed by dividing by the minimum
24432+
* can be traced to this rather than debugged as a spike. */
24433+
if (!(world->flags & EcsWorldFrameMinDeltaWarned)) {
24434+
world->flags |= EcsWorldFrameMinDeltaWarned;
24435+
ecs_warn("clock did not advance between frames, "
24436+
"reporting minimal delta time");
24437+
}
24438+
}
2442024439

2442124440
world->frame_start_time = t;
24441+
world->flags |= EcsWorldFrameStartTimeSet;
2442224442

2442324443
/* Keep track of total time passed in world */
2442424444
world->info.world_time_total_raw += (double)delta_time;
@@ -79607,8 +79627,15 @@ void ecs_world_stats_get(
7960779627
ECS_COUNTER_RECORD(&s->performance.merge_time, t, world->info.merge_time_total);
7960879628
ECS_COUNTER_RECORD(&s->performance.rematch_time, t, world->info.rematch_time_total);
7960979629
ECS_GAUGE_RECORD(&s->performance.delta_time, t, delta_world_time);
79610-
if (ECS_NEQZERO(delta_world_time) && ECS_NEQZERO(delta_frame_count)) {
79611-
ECS_GAUGE_RECORD(&s->performance.fps, t, (double)1 / (delta_world_time / (double)delta_frame_count));
79630+
double avg_frame_time = 0;
79631+
if (ECS_NEQZERO(delta_frame_count)) {
79632+
avg_frame_time = delta_world_time / delta_frame_count;
79633+
}
79634+
79635+
/* Frames whose clock did not advance report the minimum delta, which is
79636+
* not a measurable frame rate. Report 0, like the world summary. */
79637+
if (avg_frame_time > (double)ECS_FRAME_MIN_DELTA_TIME) {
79638+
ECS_GAUGE_RECORD(&s->performance.fps, t, (double)1 / avg_frame_time);
7961279639
} else {
7961379640
ECS_GAUGE_RECORD(&s->performance.fps, t, 0);
7961479641
}
@@ -80324,7 +80351,12 @@ static void flecs_copy_world_summary(
8032480351

8032580352
dst->target_fps = (double)info->target_fps;
8032680353
dst->time_scale = (double)info->time_scale;
80327-
dst->fps = 1.0 / (double)info->delta_time_raw;
80354+
/* A delta at or below the reported minimum means no frame has run yet,
80355+
* the clock did not advance, or the application passed a degenerate
80356+
* delta. None of those is a meaningful rate, so report zero. */
80357+
dst->fps = (info->delta_time_raw > ECS_FRAME_MIN_DELTA_TIME)
80358+
? 1.0 / (double)info->delta_time_raw
80359+
: 0.0;
8032880360

8032980361
dst->frame_time_frame = (double)info->frame_time_total - dst->frame_time_total;
8033080362
dst->system_time_frame = (double)info->system_time_total - dst->system_time_total;

distr/flecs.h

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -648,6 +648,8 @@ extern "C" {
648648
#define EcsWorldMeasureSystemTime (1u << 6)
649649
#define EcsWorldMultiThreaded (1u << 7)
650650
#define EcsWorldFrameInProgress (1u << 8)
651+
#define EcsWorldFrameStartTimeSet (1u << 9)
652+
#define EcsWorldFrameMinDeltaWarned (1u << 10)
651653

652654
////////////////////////////////////////////////////////////////////////////////
653655
//// OS API flags
@@ -13070,6 +13072,13 @@ extern "C" {
1307013072
*
1307113073
* This function should only be run from the main thread.
1307213074
*
13075+
* When the clock does not advance in between two measurements, a minimal
13076+
* nonzero delta time is returned instead of blocking until it does. The time
13077+
* that was not reported is credited to the frame in which the clock next
13078+
* advances. The first such frame logs a warning. Code that derives a rate by
13079+
* dividing by the delta time should treat a delta at or below 1e-9 as a frame
13080+
* in which no time could be measured, rather than as a rate.
13081+
*
1307313082
* @param world The world.
1307413083
* @param delta_time Time elapsed since the last frame.
1307513084
* @return The provided delta_time, or measured time if 0 was provided.

distr/flecs_no_addons.c

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2598,6 +2598,13 @@ bool flecs_component_is_delete_locked(
25982598
/* Used in id records to keep track of entities used with id flags */
25992599
extern const ecs_entity_t EcsFlag;
26002600

2601+
/* Smallest delta time reported for a frame. Reported instead of zero when the
2602+
* clock did not advance in between two measurements; consumers that derive a
2603+
* rate from the frame delta test against it to tell a stalled frame apart from
2604+
* a very short one. Rounds to zero (disabling both) if ecs_ftime_t is redefined
2605+
* to an integer or fixed point type. */
2606+
#define ECS_FRAME_MIN_DELTA_TIME ((ecs_ftime_t)1e-9)
2607+
26012608
////////////////////////////////////////////////////////////////////////////////
26022609
//// Bootstrap API
26032610
////////////////////////////////////////////////////////////////////////////////

distr/flecs_no_addons.h

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -468,6 +468,8 @@ extern "C" {
468468
#define EcsWorldMeasureSystemTime (1u << 6)
469469
#define EcsWorldMultiThreaded (1u << 7)
470470
#define EcsWorldFrameInProgress (1u << 8)
471+
#define EcsWorldFrameStartTimeSet (1u << 9)
472+
#define EcsWorldFrameMinDeltaWarned (1u << 10)
471473

472474
////////////////////////////////////////////////////////////////////////////////
473475
//// OS API flags

include/flecs/addons/frame.h

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -38,6 +38,13 @@ extern "C" {
3838
*
3939
* This function should only be run from the main thread.
4040
*
41+
* When the clock does not advance in between two measurements, a minimal
42+
* nonzero delta time is returned instead of blocking until it does. The time
43+
* that was not reported is credited to the frame in which the clock next
44+
* advances. The first such frame logs a warning. Code that derives a rate by
45+
* dividing by the delta time should treat a delta at or below 1e-9 as a frame
46+
* in which no time could be measured, rather than as a rate.
47+
*
4148
* @param world The world.
4249
* @param delta_time Time elapsed since the last frame.
4350
* @return The provided delta_time, or measured time if 0 was provided.

include/flecs/private/api_flags.h

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -24,6 +24,8 @@ extern "C" {
2424
#define EcsWorldMeasureSystemTime (1u << 6)
2525
#define EcsWorldMultiThreaded (1u << 7)
2626
#define EcsWorldFrameInProgress (1u << 8)
27+
#define EcsWorldFrameStartTimeSet (1u << 9)
28+
#define EcsWorldFrameMinDeltaWarned (1u << 10)
2729

2830
////////////////////////////////////////////////////////////////////////////////
2931
//// OS API flags

src/addons/frame.c

Lines changed: 31 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -67,28 +67,41 @@ static ecs_ftime_t flecs_start_measure_frame(
6767
(ECS_EQZERO(user_delta_time)))
6868
{
6969
ecs_time_t t = world->frame_start_time;
70-
do {
71-
if (world->frame_start_time.nanosec || world->frame_start_time.sec){
72-
delta_time = flecs_insert_sleep(world, &t);
70+
71+
/* A simulated clock can legitimately start at 0, so the frame start
72+
* time itself can't tell whether a previous frame measured one. */
73+
if (world->flags & EcsWorldFrameStartTimeSet) {
74+
delta_time = flecs_insert_sleep(world, &t);
75+
} else {
76+
ecs_time_measure(&t);
77+
if (ECS_NEQZERO(world->info.target_fps)) {
78+
delta_time = (ecs_ftime_t)1.0 / world->info.target_fps;
7379
} else {
74-
ecs_time_measure(&t);
75-
if (ECS_NEQZERO(world->info.target_fps)) {
76-
delta_time = (ecs_ftime_t)1.0 / world->info.target_fps;
77-
} else {
78-
/* Best guess */
79-
delta_time = (ecs_ftime_t)1.0 / (ecs_ftime_t)60.0;
80-
81-
if (ECS_EQZERO(delta_time)) {
82-
delta_time = user_delta_time;
83-
break;
84-
}
85-
}
80+
/* Best guess */
81+
delta_time = (ecs_ftime_t)1.0 / (ecs_ftime_t)60.0;
8682
}
87-
88-
/* Keep trying while delta_time is zero */
89-
} while (ECS_EQZERO(delta_time));
83+
}
84+
85+
if (delta_time < ECS_FRAME_MIN_DELTA_TIME) {
86+
/* A coarse or host-stepped clock can legitimately return the same
87+
* instant twice. Report the smallest nonzero delta rather than
88+
* measure again until the clock moves, which never returns on a
89+
* host-stepped clock. The frame start time is unchanged, so the
90+
* elapsed time is credited in full to the frame in which the
91+
* clock next advances. */
92+
delta_time = ECS_FRAME_MIN_DELTA_TIME;
93+
94+
/* Once per world, so a rate computed by dividing by the minimum
95+
* can be traced to this rather than debugged as a spike. */
96+
if (!(world->flags & EcsWorldFrameMinDeltaWarned)) {
97+
world->flags |= EcsWorldFrameMinDeltaWarned;
98+
ecs_warn("clock did not advance between frames, "
99+
"reporting minimal delta time");
100+
}
101+
}
90102

91103
world->frame_start_time = t;
104+
world->flags |= EcsWorldFrameStartTimeSet;
92105

93106
/* Keep track of total time passed in world */
94107
world->info.world_time_total_raw += (double)delta_time;

src/addons/stats/stats.c

Lines changed: 9 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -256,8 +256,15 @@ void ecs_world_stats_get(
256256
ECS_COUNTER_RECORD(&s->performance.merge_time, t, world->info.merge_time_total);
257257
ECS_COUNTER_RECORD(&s->performance.rematch_time, t, world->info.rematch_time_total);
258258
ECS_GAUGE_RECORD(&s->performance.delta_time, t, delta_world_time);
259-
if (ECS_NEQZERO(delta_world_time) && ECS_NEQZERO(delta_frame_count)) {
260-
ECS_GAUGE_RECORD(&s->performance.fps, t, (double)1 / (delta_world_time / (double)delta_frame_count));
259+
double avg_frame_time = 0;
260+
if (ECS_NEQZERO(delta_frame_count)) {
261+
avg_frame_time = delta_world_time / delta_frame_count;
262+
}
263+
264+
/* Frames whose clock did not advance report the minimum delta, which is
265+
* not a measurable frame rate. Report 0, like the world summary. */
266+
if (avg_frame_time > (double)ECS_FRAME_MIN_DELTA_TIME) {
267+
ECS_GAUGE_RECORD(&s->performance.fps, t, (double)1 / avg_frame_time);
261268
} else {
262269
ECS_GAUGE_RECORD(&s->performance.fps, t, 0);
263270
}

src/addons/stats/world_summary.c

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -20,7 +20,12 @@ static void flecs_copy_world_summary(
2020

2121
dst->target_fps = (double)info->target_fps;
2222
dst->time_scale = (double)info->time_scale;
23-
dst->fps = 1.0 / (double)info->delta_time_raw;
23+
/* A delta at or below the reported minimum means no frame has run yet,
24+
* the clock did not advance, or the application passed a degenerate
25+
* delta. None of those is a meaningful rate, so report zero. */
26+
dst->fps = (info->delta_time_raw > ECS_FRAME_MIN_DELTA_TIME)
27+
? 1.0 / (double)info->delta_time_raw
28+
: 0.0;
2429

2530
dst->frame_time_frame = (double)info->frame_time_total - dst->frame_time_total;
2631
dst->system_time_frame = (double)info->system_time_total - dst->system_time_total;

src/private_api.h

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,13 @@
5656
/* Used in id records to keep track of entities used with id flags */
5757
extern const ecs_entity_t EcsFlag;
5858

59+
/* Smallest delta time reported for a frame. Reported instead of zero when the
60+
* clock did not advance in between two measurements; consumers that derive a
61+
* rate from the frame delta test against it to tell a stalled frame apart from
62+
* a very short one. Rounds to zero (disabling both) if ecs_ftime_t is redefined
63+
* to an integer or fixed point type. */
64+
#define ECS_FRAME_MIN_DELTA_TIME ((ecs_ftime_t)1e-9)
65+
5966
////////////////////////////////////////////////////////////////////////////////
6067
//// Bootstrap API
6168
////////////////////////////////////////////////////////////////////////////////

0 commit comments

Comments
 (0)