Project homepage Mailing List  Warmcat.com  API Docs  Github Mirror 
    npro  
 Modern all-safe Rust Network Protocol library supporting h1, h2, h3, ws, wt sans-IO and with socket IO + tls
git clone https://npro.rs/repo/npro
 
root / src / server / s-resource.c
Author[]Andy Green <andy@warmcat.com> 2026-09-27 02:12 UTC
Committer[]Andy Green <andy@warmcat.com> 2026-09-27 02:12 UTC
Tree5c14557932624be933442291a780aa7b5770279d   Raw Patch
 
builder: don't decide job dir ages from a wall clock that was stepped
builder: don't decide job dir ages from a wall clock that was stepped

A builder VM commonly boots with a nonsense date and has ntp correct it a
moment later.  Job dir ages are wall clock now minus the dir's mtime
(lws_now_secs() is gettimeofday(), unlike lws_now_usecs() which is
CLOCK_MONOTONIC), so a forward step makes every dir written before it look
exactly that much older than it really is: a job dir created seconds ago
looks a day and a half old, is past the 24h threshold, and is deleted
while its task is still building, which the next step then reports as

  line 18: cd: /home/sai/jobs/XXXXXXXX/src: No such file or directory

A backward step was worse: the mtimes are then in the future and the
unsigned age subtraction wrapped to an enormous number, so every job dir
looked ancient.  Clamp that, and compare the two clocks' progress to
notice a step at all; once one is seen, stop deciding anything from ages
for an hour of monotonic time, since a pre-step mtime cannot be told from
a genuinely old one.  Removing old job dirs is housekeeping and the next
pass will do it.  The free_kib path's own young-dir floor is derived from
the same ages, so it defers too.

A step is also reported into the log of anything being built, since it
explains the jump the task is about to show in its own log timestamps.

Belt as well as braces: hold the system state below TIME_VALID while the
wall clock is still reading a pre-2025 date, so we do not create job dirs
with mtimes from a clock that is about to move (TLS certificate validity
is decided by the same clock).  The builder is already registered as a
system state notifier, so this needs no ntp client of its own and does not
compete with the ntpd already running on the box.  It gives up after five
minutes and starts anyway: a builder that never appears is worse than one
with a wrong clock, and the step detection covers the correction whenever
it lands.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
diff --git a/src/builder/b-deletion.c b/src/builder/b-deletion.c index 8eb7f30..f17bd3d 100644 --- a/src/builder/b-deletion.c +++ b/src/builder/b-deletion.c @@ -399,6 +399,102 @@ sai_deletion_worker(const char *home_dir_unused) */ /* + * Wall clock step detection + * + * A builder VM commonly boots with a nonsense date and has ntp correct it a + * moment later. Job dir ages are wall clock now minus the dir's mtime, so a + * forward step makes every dir written before it look exactly that much older + * than it is -- a job dir created seconds ago looks a day and a half old, is + * past the 24h threshold, and gets deleted while its task is still building. + * A backward step is worse: the mtimes are then in the future, and the age + * subtraction below used to wrap to an enormous number, so everything went. + * + * We cannot tell a pre-step mtime from a genuinely old one, so once a step is + * seen we simply stop deciding anything from ages for a while. Removing old + * job dirs is housekeeping and the next pass will do it. + */ + +void +saib_clock_baseline(void) +{ + builder.mono_at_base = lws_now_usecs(); + builder.wall_at_base = (uint64_t)lws_now_secs(); + builder.mono_last_clock_step = 0; +} + +int +saib_clock_ages_trustworthy(void) +{ + lws_usec_t mono = lws_now_usecs(); + uint64_t wall = (uint64_t)lws_now_secs(), expect; + int64_t delta; + + if (!builder.wall_at_base) { + /* nothing has baselined us yet, so this is the baseline */ + saib_clock_baseline(); + + return 1; + } + + expect = builder.wall_at_base + + (uint64_t)((mono - builder.mono_at_base) / LWS_US_PER_SEC); + + delta = (int64_t)wall - (int64_t)expect; + + if (delta > SAI_CLOCK_STEP_TOLERANCE_SECS || + delta < -SAI_CLOCK_STEP_TOLERANCE_SECS) { + + lwsl_warn("%s: wall clock stepped by %llds (ntp on a VM that " + "booted with the wrong date?): not trusting job dir " + "ages for the next %ds\n", __func__, + (long long)delta, SAI_CLOCK_STEP_SETTLE_SECS); + + /* + * Tell anything we are building, since this also explains the + * jump it is about to see in its own log timestamps + */ + + lws_start_foreach_dll(struct lws_dll2 *, d, + builder.sai_plat_owner.head) { + sai_plat_t *sp = lws_container_of(d, sai_plat_t, + sai_plat_list); + + lws_start_foreach_dll(struct lws_dll2 *, d2, + sp->nspawn_owner.head) { + struct sai_nspawn *ns = lws_container_of(d2, + struct sai_nspawn, list); + + saib_task_logf(ns->spm, ns, NULL, + "the builder's wall clock just stepped " + "by %llds, most likely ntp correcting a " + "VM that booted with the wrong date", + (long long)delta); + + } lws_end_foreach_dll(d2); + } lws_end_foreach_dll(d); + + /* rebase, so a single step is only reported once */ + + builder.wall_at_base = wall; + builder.mono_at_base = mono; + builder.mono_last_clock_step = mono; + + return 0; + } + + if (!builder.mono_last_clock_step) + return 1; + + if (mono - builder.mono_last_clock_step < + (lws_usec_t)SAI_CLOCK_STEP_SETTLE_SECS * LWS_US_PER_SEC) + return 0; + + builder.mono_last_clock_step = 0; + + return 1; +} + +/* * Job dir holds * * A task's build steps are each offered, run and destroyed separately, so @@ -512,6 +608,8 @@ struct cleanup_ctx { struct lwsac *ac; struct inactive_job *inactive_head; int inactive_count; + /* may we believe wall-clock-derived file ages on this pass? */ + char ages_trustworthy; }; struct active_job_uuid { @@ -588,9 +686,20 @@ scan_jobs_dir_cb(const char *dirpath, void *user, struct lws_dir_entry *lde) /* older than 24h? */ - age = (uint64_t)lws_now_secs() - (uint64_t)sb.st_mtime; + { + uint64_t now = (uint64_t)lws_now_secs(); + + /* + * An mtime in the future means the clock went backwards since + * the dir was written; it does not mean the dir is older than + * the epoch, which is what the unsigned subtraction used to + * produce + */ + age = now > (uint64_t)sb.st_mtime ? + now - (uint64_t)sb.st_mtime : 0; + } - if (age > SAI_CLEANUP_JOB_DIR_MIN_AGE_SECS) { + if (age > SAI_CLEANUP_JOB_DIR_MIN_AGE_SECS && ctx->ages_trustworthy) { lwsl_info("%s: requesting removal of old job dir %s (age %llus)\n", __func__, path, (unsigned long long)age); @@ -634,6 +743,7 @@ saib_deletion_free_kib(unsigned int needed_kib, const char *protect_vn) return 0; memset(&ctx, 0, sizeof(ctx)); + ctx.ages_trustworthy = (char)saib_clock_ages_trustworthy(); /* find out the uuids of any active jobs */ lws_start_foreach_dll_safe(struct lws_dll2 *, d, d1, b->sai_plat_owner.head) { @@ -686,7 +796,8 @@ saib_deletion_free_kib(unsigned int needed_kib, const char *protect_vn) * taking it just breaks that build instead of * fixing our disk problem. */ - if (ij->age >= SAI_FREEKIB_JOB_DIR_MIN_AGE_SECS) + if (ctx.ages_trustworthy && + ij->age >= SAI_FREEKIB_JOB_DIR_MIN_AGE_SECS) sorted[candidates++] = ij; else lwsl_info("%s: sparing %s, only %llus old\n", @@ -696,10 +807,14 @@ saib_deletion_free_kib(unsigned int needed_kib, const char *protect_vn) } if (!candidates) { - lwsl_warn("%s: need %uMiB, only %uMiB free, but no " - "job dir is old enough to remove\n", + lwsl_warn("%s: need %uMiB, only %uMiB free, but " + "no job dir is old enough to remove%s\n", __func__, needed_kib / 1024, - free_kib / 1024); + free_kib / 1024, + ctx.ages_trustworthy ? "" : + " (and the wall clock stepped " + "recently, so their ages cannot be " + "believed)"); goto done; } @@ -739,6 +854,7 @@ sul_cleanup_jobs_cb(lws_sorted_usec_list_t *sul) lwsl_info("%s: starting periodic cleanup\n", __func__); memset(&ctx, 0, sizeof(ctx)); + ctx.ages_trustworthy = (char)saib_clock_ages_trustworthy(); /* * We must not delete any active job directories, find out the uuids diff --git a/src/builder/b-private.h b/src/builder/b-private.h index 5bcbafc..643aca0 100644 --- a/src/builder/b-private.h +++ b/src/builder/b-private.h @@ -107,6 +107,34 @@ struct saib_opaque_spawn { * task that died on the server side pinning its job dir forever. */ #define SAI_JOBDIR_HOLD_MAX_SECS (2u * 3600u) +/* + * How far the wall clock and the monotonic clock may disagree about how much + * time has passed before we call it a step rather than drift. ntp slews both, + * so in normal running they track each other within a second. + */ +#define SAI_CLOCK_STEP_TOLERANCE_SECS 60 +/* + * After the wall clock has been stepped, every mtime written before the step is + * wrong by the size of the step, and there is no way to tell one from a + * genuinely old file. So stop making age-based decisions for this long (of + * monotonic time) afterwards. Deleting old job dirs is only housekeeping; it + * can always wait for the next pass. + */ +#define SAI_CLOCK_STEP_SETTLE_SECS (60 * 60) +/* + * A wall clock reading before this is not a clock that has been set yet, it is + * a VM that has just booted. It only has to be later than any default date a + * builder might come up with and earlier than now, so it never needs moving; + * a clock that is wrong but still after it is caught by the step detection + * above instead. (2025-01-01 UTC) + */ +#define SAI_CLOCK_PLAUSIBLE_AFTER 1735689600ull +/* + * How long to wait for the clock to be set before starting work anyway. A + * builder that never appears is worse than one with a wrong clock, and the step + * detection above stops a late correction eating the job dirs regardless. + */ +#define SAI_CLOCK_WAIT_MAX_SECS (5 * 60) struct saib_ws_pss; @@ -177,6 +205,7 @@ struct sai_builder { lws_sorted_usec_list_t sul_power; /* current power state's deadline */ lws_sorted_usec_list_t sul_stay; lws_sorted_usec_list_t sul_cleanup_jobs; + lws_sorted_usec_list_t sul_clock_wait; lws_sorted_usec_list_t sul_deletion_respawn; #if defined(__APPLE__) @@ -242,6 +271,17 @@ struct sai_builder { uint64_t disk_reserved_kib; /* + * Wall clock vs monotonic clock baseline, for noticing that something + * (ntp, usually, on a VM that booted with a nonsense date) has stepped + * the wall clock under us. Job dir ages are wall clock minus file + * mtime, so a step makes every existing job dir look as old as the step + * was big, and the deletion paths take dirs that are still in use. + */ + uint64_t wall_at_base; /* lws_now_secs() */ + lws_usec_t mono_at_base; + lws_usec_t mono_last_clock_step; /* 0: none seen */ + + /* * Strictly-increasing log chunk timestamp latch. It is builder-wide * and not per-nspawn: a task's steps are each a separate nspawn, and * the browser pages a task's logs with a strictly-greater-than @@ -457,6 +497,17 @@ saib_jobdir_holds_destroy(void); */ void saib_task_jobdir_vn(char *dest, size_t dest_len, const char *task_uuid); + +/* + * Wall clock step detection. saib_clock_baseline() records where the two + * clocks started out; saib_clock_ages_trustworthy() reports whether file ages + * computed from the wall clock can be believed right now, and notices (and + * reports) a step as a side effect of being asked. + */ +void +saib_clock_baseline(void); +int +saib_clock_ages_trustworthy(void); int saib_reassess_idle_situation(void); void diff --git a/src/builder/b-sai.c b/src/builder/b-sai.c index 7c1eb74..8672c34 100644 --- a/src/builder/b-sai.c +++ b/src/builder/b-sai.c @@ -350,6 +350,28 @@ saib_create_resproxy_listen_uds(struct lws_context *context, return 0; } +/* + * A builder VM often boots with a nonsense wall clock and has ntp correct it a + * moment later. We should not start work before then: everything we create + * gets an mtime from the bad clock, and once the step lands those mtimes make + * the job dirs look as old as the step was big, so the deletion paths remove + * dirs whose task is still building. TLS certificate validity is decided by + * the same clock. + * + * So hold the system state below TIME_VALID until the clock is at least + * plausible. We rejected the transition, so we own retrying it. + */ + +static lws_usec_t clock_wait_started; + +static void +sul_clock_wait_cb(lws_sorted_usec_list_t *sul) +{ + lws_state_transition_steps( + lws_system_get_state_manager(builder.context), + LWS_SYSTATE_OPERATIONAL); +} + static int app_system_state_nf(lws_state_manager_t *mgr, lws_state_notify_link_t *link, int current, int target) @@ -361,6 +383,47 @@ app_system_state_nf(lws_state_manager_t *mgr, lws_state_notify_link_t *link, */ switch (target) { + case LWS_SYSTATE_TIME_VALID: + if (current >= LWS_SYSTATE_TIME_VALID) + break; + + if ((uint64_t)lws_now_secs() >= SAI_CLOCK_PLAUSIBLE_AFTER) { + if (clock_wait_started) + lwsl_notice("%s: wall clock now reads %llu, " + "starting work\n", __func__, + (unsigned long long)lws_now_secs()); + + /* the clock is believable, this is where we start from */ + saib_clock_baseline(); + break; + } + + if (!clock_wait_started) { + clock_wait_started = lws_now_usecs(); + lwsl_warn("%s: wall clock reads %llu, before %llu: it has " + "not been set yet, holding off starting work " + "for up to %ds\n", __func__, + (unsigned long long)lws_now_secs(), + (unsigned long long)SAI_CLOCK_PLAUSIBLE_AFTER, + SAI_CLOCK_WAIT_MAX_SECS); + } else + if (lws_now_usecs() - clock_wait_started > + (lws_usec_t)SAI_CLOCK_WAIT_MAX_SECS * LWS_US_PER_SEC) { + lwsl_err("%s: wall clock still reads %llu after " + "%ds: starting work anyway, but expect " + "anything that cares about dates to be " + "wrong until it is set\n", __func__, + (unsigned long long)lws_now_secs(), + SAI_CLOCK_WAIT_MAX_SECS); + saib_clock_baseline(); + break; + } + + lws_sul_schedule(mgr->context, 0, &builder.sul_clock_wait, + sul_clock_wait_cb, 2 * LWS_US_PER_SEC); + + return 1; + case LWS_SYSTATE_CONTEXT_CREATED: { struct lws_context_creation_info info;
Page fetched 0s ago, creation time: 3ms (vhost etag hits: 0%, cache hits: 0%)