diff --git a/src/controller/include/cluster.h b/src/controller/include/cluster.h index 3911ec29..2090d9f9 100644 --- a/src/controller/include/cluster.h +++ b/src/controller/include/cluster.h @@ -269,6 +269,14 @@ extern int record_job_reconcile_assign_fact(cluster_t*, job_t*, worker_t*, extern int record_job_finish_fact_at(cluster_t*, job_t*, xce_jobfinish_t*, uint64_t); +/* bug-1747: record_job_fail_fact's sibling taking the failure time + * (MILLISECONDS, like record_job_finish_fact_at) to record as the job's + * finish_time; 0 means "not known, use receipt time". Same locking and + * DEFERRED contract as record_job_finish_fact_at. on_job_fail() uses + * receipt time; resync.c passes the worker-reported time. */ +extern int record_job_fail_fact_at(cluster_t*, job_t*, job_failinfo_t*, + uint64_t); + extern int on_job_start(cluster_t*, job_pidinfo_t*); extern int on_job_finish(cluster_t*, xce_jobfinish_t*); extern int on_job_fail(cluster_t*, job_failinfo_t*); diff --git a/src/controller/include/resync.h b/src/controller/include/resync.h index 313738dd..962b6e23 100644 --- a/src/controller/include/resync.h +++ b/src/controller/include/resync.h @@ -124,11 +124,9 @@ extern int resync_round_is_current(worker_t* w, uint64_t token); * (Req 4.2). record_job_finish_fact() itself is unmodified; its own * caller (on_job_finish, an ordinary worker report) still uses * receipt-time, correctly, for that near-instantaneous case. - * - JobStateStatus_finishedFail: routed through on_job_fail() (job.c), - * unchanged -- Requirement 4.2 remains unsatisfiable for this outcome - * via any existing path in this codebase (WAL_JOB_FAIL carries no - * finish-time slot at any layer, for any caller -- a pre-existing, - * systemic gap that predates this feature; see buglog.json bug-1747). + * - JobStateStatus_finishedFail: routed through record_job_fail_fact_at() + * (bug-1747, job.c), so the recorded finish_time is entry->finish_time_ms + * (receipt time when 0) and the exit code is kept (bug-1754). * - Both finished outcomes apply identically whether entry->queried is * true or false (Req 4.7: an unqueried finished extra reconciles * through the same path as a queried one; there is no "assign" case for diff --git a/src/controller/job.c b/src/controller/job.c index 11f1a047..10ef92ce 100644 --- a/src/controller/job.c +++ b/src/controller/job.c @@ -2787,6 +2787,34 @@ int record_job_finish_fact_at(cluster_t* c, job_t* job, return 0; } +/* bug-1747: see cluster.h. The durable-append body record_job_fail_fact() + * used to hold, plus the failure time: `finish_time_ms` (MILLISECONDS, as + * the worker reports it -- see record_job_finish_fact_at) or, when 0, + * receipt time. It is written as SECONDS into WAL_JOB_FAIL's trailer so + * every apply of the fact -- live, restart replay, standby catch-up -- + * yields the same job.finish_time instead of its own time(NULL). */ +int record_job_fail_fact_at(cluster_t* c, job_t* job, + job_failinfo_t* failinfo, uint64_t finish_time_ms) +{ + uint64_t finish_time = (finish_time_ms != 0) + ? finish_time_ms / 1000 + : (uint64_t)time(NULL); + + xce_run_hooks(&(c->hooksys), XCE_CONTROLLER_HOOK_JOB, HOOK_BEFORE_EVENT, + HOOK_DETAIL_JOB_FAIL, c, failinfo, job); + + /* Durable append only -- no mutation of the real `job`, no AFTER_EVENT + * firing here (Req 5.1, 5.3); apply_committed_entry() routes the + * STAGE_FLAG'd fact to apply_job_fail_transition() at apply time. + * bug-1754: failinfo->code rides along so apply time can record the + * job's exit code (apply_job_fail_exit_code). */ + (void)persist_submit_job_fail_fact(&c->persist, job->job.jobid, + failinfo->stage, failinfo->code, + finish_time); + + return 0; +} + int on_job_finish(cluster_t* c, xce_jobfinish_t* finish) { job_t* job = NULL; @@ -2916,21 +2944,7 @@ static int mark_job_fail(cluster_t* c, job_t* job, job_failinfo_t* failinfo) static int record_job_fail_fact(cluster_t* c, job_t* job, job_failinfo_t* failinfo) { - xce_run_hooks(&(c->hooksys), XCE_CONTROLLER_HOOK_JOB, HOOK_BEFORE_EVENT, - HOOK_DETAIL_JOB_FAIL, c, failinfo, job); - - /* Durable append only — no mutation of the real `job`, no AFTER_EVENT - * firing here (Req 5.1, 5.3). `state` is unused for this apply-time- - * recomputed shape (0 is written for forward-compatibility/diagnostics - * only); the WAL_JOB_FAIL_STAGE_FLAG bit in `_pad` tells - * apply_committed_entry() to route it to the real - * apply_job_fail_transition() core instead of an absolute overwrite. - * bug-1754: failinfo->code rides along as a trailer so apply time can - * record the job's exit code (apply_job_fail_exit_code). */ - (void)persist_submit_job_fail_fact(&c->persist, job->job.jobid, - failinfo->stage, failinfo->code); - - return 0; + return record_job_fail_fact_at(c, job, failinfo, 0); } /* Guarded state-transition core for an UPDATE, extracted from diff --git a/src/controller/persist.c b/src/controller/persist.c index f65b632f..7421595d 100644 --- a/src/controller/persist.c +++ b/src/controller/persist.c @@ -4123,6 +4123,7 @@ int apply_wal_entry(persist_t* p, uint32_t type, uint64_t lsn, & WAL_JOB_FAIL_STAGE_FLAG)) { const wal_jobstate_t* js = (const wal_jobstate_t*)payload; int32_t wire_code = 0; + uint64_t wire_time = 0; bool have_code = payload_len >= sizeof(wal_jobstate_t) + sizeof(wire_code); job_t* j = NULL; @@ -4131,6 +4132,12 @@ int apply_wal_entry(persist_t* p, uint32_t type, uint64_t lsn, memcpy(&wire_code, (const uint8_t*)payload + sizeof(wal_jobstate_t), sizeof(wire_code)); + if (payload_len >= sizeof(wal_jobstate_t) + sizeof(wire_code) + + sizeof(wire_time)) + memcpy(&wire_time, + (const uint8_t*)payload + sizeof(wal_jobstate_t) + + sizeof(wire_code), + sizeof(wire_time)); lock(p->cluster->jobmgr, RTTI_LOCK_READ); key_find(p->cluster->jobmgr, (void*)js->jobid, (void**)&j); @@ -4145,9 +4152,12 @@ int apply_wal_entry(persist_t* p, uint32_t type, uint64_t lsn, lock(j, RTTI_LOCK_WRITE); if (apply_job_fail_transition(j, &failinfo) - == JOB_TRANSITION_APPLIED - && have_code) - apply_job_fail_exit_code(j, &failinfo); + == JOB_TRANSITION_APPLIED) { + if (have_code) + apply_job_fail_exit_code(j, &failinfo); + if (wire_time != 0) + j->job.finish_time = (time_t)wire_time; + } unlock(j); } break; @@ -5046,16 +5056,26 @@ int apply_committed_entry(persist_t* p, uint32_t wal_type, uint64_t lsn, job_failinfo_t failinfo; bool have_failinfo = false; if (js->_pad & WAL_JOB_FAIL_STAGE_FLAG) { - int32_t wire_code = 0; - bool have_code = len >= sizeof(wal_jobstate_t) - + sizeof(wire_code); + int32_t wire_code = 0; + uint64_t wire_time = 0; + bool have_code = len >= sizeof(wal_jobstate_t) + + sizeof(wire_code); + bool have_time = len >= sizeof(wal_jobstate_t) + + sizeof(wire_code) + + sizeof(wire_time); - /* bug-1754: persist_submit_job_fail_fact()'s int32_t code - * trailer; absent on entries written before the fix. */ + /* bug-1754/bug-1747: persist_submit_job_fail_fact()'s int32_t + * code + uint64_t finish_time trailer; older entries carry + * neither (pre-bug-1754) or only the code (bug-1754). */ if (have_code) memcpy(&wire_code, (const uint8_t*)payload + sizeof(wal_jobstate_t), sizeof(wire_code)); + if (have_time) + memcpy(&wire_time, + (const uint8_t*)payload + sizeof(wal_jobstate_t) + + sizeof(wire_code), + sizeof(wire_time)); failinfo = (job_failinfo_t){ .jobid = js->jobid, @@ -5067,6 +5087,8 @@ int apply_committed_entry(persist_t* p, uint32_t wal_type, uint64_t lsn, result = apply_job_fail_transition(j, &failinfo); if (have_code && result == JOB_TRANSITION_APPLIED) apply_job_fail_exit_code(j, &failinfo); + if (wire_time != 0 && result == JOB_TRANSITION_APPLIED) + j->job.finish_time = (time_t)wire_time; } else { result = apply_job_update_transition(j, (int)js->state); } @@ -8115,18 +8137,20 @@ int persist_submit_job_finish_fact(persist_t* p, uint64_t jobid, int state, payload, (uint32_t)sizeof(payload)); } -/* bug-1754: see persist.h's doc comment. Same native fixed-size trailer - * style as persist_submit_job_finish_fact() above. */ +/* bug-1754/bug-1747: see persist.h's doc comment. Same native fixed-size + * trailer style as persist_submit_job_finish_fact() above. */ int persist_submit_job_fail_fact(persist_t* p, uint64_t jobid, uint32_t stage, - int code) + int code, uint64_t finish_time) { wal_jobstate_t js = { .jobid = jobid, .state = 0, ._pad = WAL_JOB_FAIL_STAGE_FLAG | stage }; int32_t c32 = (int32_t)code; - uint8_t payload[sizeof(js) + sizeof(c32)]; + uint8_t payload[sizeof(js) + sizeof(c32) + sizeof(finish_time)]; memcpy(payload, &js, sizeof(js)); memcpy(payload + sizeof(js), &c32, sizeof(c32)); + memcpy(payload + sizeof(js) + sizeof(c32), &finish_time, + sizeof(finish_time)); return wal_hook_append_classified(p, WAL_JOB_FAIL, WAL_MODE_RETAIN, payload, (uint32_t)sizeof(payload)); diff --git a/src/controller/resync.c b/src/controller/resync.c index 814d49ca..5c6aa215 100644 --- a/src/controller/resync.c +++ b/src/controller/resync.c @@ -639,18 +639,12 @@ static void resync_apply_running_entry(cluster_t* c, worker_t* w, * the job table is a silent no-op, mirroring on_job_finish()'s own * "can not find job" behavior for an unknown jobid. * - * finishedFail: still routed through the existing, UNMODIFIED on_job_fail() - * /record_job_fail_fact() -- Requirement 4.2 remains unsatisfiable for this - * outcome via any existing path in this codebase, not a reconciliation- - * specific gap: WAL_JOB_FAIL's payload (persist_submit_job_fail_fact(): - * stage plus, since bug-1754, the exit code) carries no finish-time slot, and apply_job_fail_transition() (job.c) - * unconditionally sets job->job.finish_time = time(NULL) at APPLY time - * (not even receipt time) for EVERY fail-reporting caller in this system, - * confirmed by direct inspection -- a pre-existing, systemic gap that - * predates this feature and is out of this task's boundary to fix (see - * buglog.json bug-1747, re-scoped). The reconciled job's STATE (EXIT) is - * always correct either way; only its recorded finish_time reflects - * apply-processing time rather than the worker's true report. */ + * finishedFail: routed through record_job_fail_fact_at() (bug-1747), the + * fail-side sibling of record_job_finish_fact_at(): the worker-reported + * finish_time_ms (receipt time when 0) and exit code (bug-1754) both ride + * WAL_JOB_FAIL's trailer, so Req 4.2 now holds for this outcome too. Same + * lookup/lock/unlock/dereference sequence as the finishedOk branch; an + * unknown jobid is a silent no-op. */ static void resync_apply_finished_entry(cluster_t* c, xce_job_state_entry_t* entry) { @@ -669,12 +663,21 @@ static void resync_apply_finished_entry(cluster_t* c, dereference(job); } } else { - job_failinfo_t fail - = { .jobid = entry->jobid, - .stage = JOB_EXEC_STAGE_MAIN, - .code = entry->exit_code, - .detail = (char*)"worker-rejoin-resync reconciliation" }; - on_job_fail(c, &fail); + job_t* job = resync_lookup_job(c, entry->jobid); + + if (job != NULL) { + job_failinfo_t fail + = { .jobid = entry->jobid, + .stage = JOB_EXEC_STAGE_MAIN, + .code = entry->exit_code, + .detail = (char*)"worker-rejoin-resync reconciliation" }; + + lock(job, RTTI_LOCK_WRITE); + record_job_fail_fact_at(c, job, &fail, entry->finish_time_ms); + unlock(job); + + dereference(job); + } } } diff --git a/src/controller/testsuite/test_wal_job_fail_fact.c b/src/controller/testsuite/test_wal_job_fail_fact.c index 92353ae2..fedade8c 100644 --- a/src/controller/testsuite/test_wal_job_fail_fact.c +++ b/src/controller/testsuite/test_wal_job_fail_fact.c @@ -32,6 +32,7 @@ #include #include #include +#include #include @@ -395,6 +396,228 @@ static void test_wjfl_real_on_job_fail_survives_restart(void) fprintf(stderr, "cleanup warning: rm -rf %s failed\n", tmp); } +/* ── bug-1747: WAL_JOB_FAIL also carries the failure time ─────────────── */ + +/* persist_submit_job_fail_fact()'s full shape: header + int32_t code + + * uint64_t finish_time (seconds). */ +typedef struct { + wal_jobstate_t js; + int32_t code; + uint64_t finish_time; +} __attribute__((packed)) wjfl_fail_payload_t2; + +static wjfl_fail_payload_t2 wjfl_fail_payload2(uint64_t jobid, uint32_t stage, + int32_t code, uint64_t ft) +{ + wjfl_fail_payload_t2 pl; + + memset(&pl, 0, sizeof(pl)); + pl.js.jobid = jobid; + pl.js._pad = WAL_JOB_FAIL_STAGE_FLAG | stage; + pl.code = code; + pl.finish_time = ft; + return pl; +} + +static void test_wjfl_apply_committed_entry_adopts_wire_finish_time(void) +{ + wjfl_setup(); + + job_t* j = wjfl_seed_job(74101, JOB_STAT_RUN); + TEST_ASSERT_NOT_NULL(j); + + wjfl_fail_payload_t2 pl + = wjfl_fail_payload2(74101, JOB_EXEC_STAGE_MAIN, 42, 1700000500ULL); + TEST_ASSERT_EQUAL_INT(0, apply_committed_entry(&g_wjfl_p, WAL_JOB_FAIL, + 410, &pl, sizeof(pl))); + + TEST_ASSERT_EQUAL_UINT32(JOB_STAT_EXIT, j->job.state); + wjfl_assert_exit_code(j->job.exit_info, 42); + TEST_ASSERT_EQUAL_UINT64_MESSAGE(1700000500ULL, + (uint64_t)j->job.finish_time, + "bug-1747: a failed job's finish_time must be the wire-carried " + "failure time, not apply-time time(NULL)"); + + wjfl_teardown(); +} + +static void test_wjfl_apply_committed_entry_code_only_payload_compat(void) +{ + wjfl_setup(); + + job_t* j = wjfl_seed_job(74102, JOB_STAT_RUN); + TEST_ASSERT_NOT_NULL(j); + + time_t before = time(NULL); + wjfl_fail_payload_t pl = wjfl_fail_payload(74102, JOB_EXEC_STAGE_MAIN, 7); + TEST_ASSERT_EQUAL_INT(0, apply_committed_entry(&g_wjfl_p, WAL_JOB_FAIL, + 411, &pl, sizeof(pl))); + + wjfl_assert_exit_code(j->job.exit_info, 7); + TEST_ASSERT_TRUE_MESSAGE(j->job.finish_time >= before, + "a code-only (bug-1754-era) payload carries no time: finish_time " + "stays apply-time, as before"); + + wjfl_teardown(); +} + +static void test_wjfl_apply_wal_entry_adopts_wire_finish_time(void) +{ + wjfl_setup(); + + job_t* j = wjfl_seed_job(74103, JOB_STAT_RUN); + TEST_ASSERT_NOT_NULL(j); + + wjfl_fail_payload_t2 pl + = wjfl_fail_payload2(74103, JOB_EXEC_STAGE_MAIN, 5, 1700000600ULL); + TEST_ASSERT_EQUAL_INT(0, apply_wal_entry(&g_wjfl_p, WAL_JOB_FAIL, 412, + &pl, sizeof(pl))); + + TEST_ASSERT_EQUAL_UINT32(JOB_STAT_EXIT, j->job.state); + wjfl_assert_exit_code(j->job.exit_info, 5); + TEST_ASSERT_EQUAL_UINT64(1700000600ULL, (uint64_t)j->job.finish_time); + + wjfl_teardown(); +} + +/* Real record_job_fail_fact_at() + WAL write + persist_recover(): a failure + * reported with an old time (as a rejoining worker reports one) keeps that + * time across a restart; a 0 time falls back to receipt time. */ +static void test_wjfl_record_fail_fact_at_survives_restart(void) +{ + char tmp[256]; + strcpy(tmp, "/tmp/xce_wjfl_failat_XXXXXX"); + TEST_ASSERT_NOT_NULL(mkdtemp(tmp)); + + const uint64_t jobid_old = 74104; + const uint64_t jobid_zero = 74105; + const uint64_t old_s = (uint64_t)time(NULL) - 86400; + time_t before, after; + + { + persist_config_t cfg; + cluster_t c; + kvmgr_params_t int_params = { .key_type = KVMGR_KEY_INT, + .nslots = 32, .delta = 16 }; + const uint64_t ids[2] = { jobid_old, jobid_zero }; + int k; + + if (makeString((char*)"wjfl-failat-probe") == NULL) + xstring_table_init(64); + if (!g_wjfl_jobobj_ready) { + TEST_ASSERT_EQUAL_INT(0, job_obj_init(32, 32)); + g_wjfl_jobobj_ready = 1; + } + + memset(&c, 0, sizeof(c)); + TEST_ASSERT_EQUAL_INT(0, + xce_hook_init(&c.hooksys, XCE_CONTROLLER_HOOK_MAX)); + c.jobmgr = makeInstance(&xkvmgr_type, &int_params); + TEST_ASSERT_NOT_NULL(c.jobmgr); + + cfg = persist_config_defaults(); + cfg.wal_sync_ms = 5000; + persist_set_workdir(&c.persist, tmp, "ctrl-test"); + TEST_ASSERT_EQUAL_INT(0, persist_init(&c.persist, &cfg, NULL)); + TEST_ASSERT_EQUAL_INT(0, persist_start(&c.persist)); + + for (k = 0; k < 2; k++) { + job_submit_data_t submit; + xce_job_t jdef; + uint8_t* buf = NULL; + size_t sz = 0; + job_t* j; + + memset(&submit, 0, sizeof(submit)); + submit.queue = (char*)"oq"; + submit.user = (char*)"tester"; + memset(&jdef, 0, sizeof(jdef)); + jdef.jobid = ids[k]; + jdef.state = JOB_STAT_PEND; + jdef.submit = &submit; + + TEST_ASSERT_EQUAL_INT(0, wjfl_encode_job(&jdef, &buf, &sz)); + TEST_ASSERT_EQUAL_INT(0, persist_wal_async(&c.persist, + WAL_JOB_SUBMIT, buf, (uint32_t)sz)); + free(buf); + + jdef.state = JOB_STAT_RUN; + j = makeJob(c.jobmgr, &jdef); + TEST_ASSERT_NOT_NULL(j); + + job_failinfo_t fail = { .jobid = ids[k], + .stage = JOB_EXEC_STAGE_MAIN, + .code = 3, + .detail = (char*)"exit" }; + before = time(NULL); + lock(j, RTTI_LOCK_WRITE); + TEST_ASSERT_EQUAL_INT(0, record_job_fail_fact_at(&c, j, &fail, + (ids[k] == jobid_old) ? old_s * 1000ULL : 0)); + unlock(j); + after = time(NULL); + } + + TEST_ASSERT_EQUAL_INT(0, persist_flush(&c.persist)); + persist_stop(&c.persist); + persist_fini(&c.persist); + dereference(c.jobmgr); + xce_hook_fini(&c.hooksys); + } + + { + persist_t* p2 = calloc(1, sizeof(persist_t)); + cluster_t c2; + job_t* j_old = NULL; + job_t* j_zero = NULL; + kvmgr_params_t int_params = { .key_type = KVMGR_KEY_INT, + .nslots = 32, .delta = 16 }; + persist_config_t cfg = persist_config_defaults(); + + TEST_ASSERT_NOT_NULL(p2); + cfg.wal_sync_ms = 5000; + persist_set_workdir(p2, tmp, "ctrl-test"); + TEST_ASSERT_EQUAL_INT(0, persist_init(p2, &cfg, NULL)); + TEST_ASSERT_EQUAL_INT(0, persist_start(p2)); + + memset(&c2, 0, sizeof(c2)); + TEST_ASSERT_EQUAL_INT(0, + xce_hook_init(&c2.hooksys, XCE_CONTROLLER_HOOK_MAX)); + c2.jobmgr = makeInstance(&xkvmgr_type, &int_params); + TEST_ASSERT_NOT_NULL(c2.jobmgr); + + p2->cluster = &c2; + TEST_ASSERT_EQUAL_INT(0, persist_recover(p2)); + + lock(c2.jobmgr, RTTI_LOCK_READ); + key_find(c2.jobmgr, (void*)jobid_old, (void**)&j_old); + key_find(c2.jobmgr, (void*)jobid_zero, (void**)&j_zero); + unlock(c2.jobmgr); + TEST_ASSERT_NOT_NULL(j_old); + TEST_ASSERT_NOT_NULL(j_zero); + + TEST_ASSERT_EQUAL_UINT32(JOB_STAT_EXIT, j_old->job.state); + wjfl_assert_exit_code(j_old->job.exit_info, 3); + TEST_ASSERT_EQUAL_UINT64_MESSAGE(old_s, (uint64_t)j_old->job.finish_time, + "bug-1747: the reported failure time must survive restart " + "replay, not become replay-time time(NULL)"); + + TEST_ASSERT_TRUE_MESSAGE(j_zero->job.finish_time >= before + && j_zero->job.finish_time <= after, + "a 0 (unknown) failure time falls back to receipt time"); + + xce_hook_fini(&c2.hooksys); + dereference(c2.jobmgr); + persist_stop(p2); + persist_fini(p2); + free(p2); + } + + char cmd[512]; + snprintf(cmd, sizeof(cmd), "rm -rf %s", tmp); + if (system(cmd) != 0) + fprintf(stderr, "cleanup warning: rm -rf %s failed\n", tmp); +} + /* ── Test group entry point ───────────────────────────────────────────── */ void test_wal_job_fail_fact(void) @@ -405,4 +628,8 @@ void test_wal_job_fail_fact(void) RUN_TEST(test_wjfl_apply_committed_entry_backward_compat_old_payload); RUN_TEST(test_wjfl_apply_wal_entry_sets_state_and_exit_info); RUN_TEST(test_wjfl_real_on_job_fail_survives_restart); + RUN_TEST(test_wjfl_apply_committed_entry_adopts_wire_finish_time); + RUN_TEST(test_wjfl_apply_committed_entry_code_only_payload_compat); + RUN_TEST(test_wjfl_apply_wal_entry_adopts_wire_finish_time); + RUN_TEST(test_wjfl_record_fail_fact_at_survives_restart); } diff --git a/src/controller/testsuite/test_worker_resync.c b/src/controller/testsuite/test_worker_resync.c index 4e7ce366..b23d63dc 100644 --- a/src/controller/testsuite/test_worker_resync.c +++ b/src/controller/testsuite/test_worker_resync.c @@ -2838,7 +2838,9 @@ static void test_full_rejoin_reconciliation_round_trip(void) .jobid = TWR_JOBID_RT_FINFAIL, .status = JobStateStatus_finishedFail, .exit_code = worker_reported_exit_code, - .finish_time_ms = 0, .queried = 1 + .finish_time_ms = (worker_reported_finish_time_s - 60) + * 1000ULL, + .queried = 1 }; e_unrec = (xce_job_state_entry_t){ .jobid = TWR_JOBID_RT_UNREC, @@ -3013,10 +3015,13 @@ static void test_full_rejoin_reconciliation_round_trip(void) TEST_ASSERT_EQUAL_UINT32_MESSAGE(JOB_STAT_EXIT, j2_finfail->job.state, "finished-failure: the DEFERRED on_job_fail/record_job_fail_" "fact fact must apply to EXIT on replay (Req 4.1)"); - /* Req 4.2 remains DOCUMENTED-unsatisfiable for the finished- - * FAILURE finish_time specifically (bug-1747) -- not asserted here. - * The worker-reported EXIT CODE, however, is durably recorded via - * WAL_JOB_FAIL's code trailer since bug-1754. */ + /* Req 4.2 for the finished-FAILURE outcome: the worker-reported + * exit code (bug-1754) and failure time (bug-1747) both ride + * WAL_JOB_FAIL's trailer and survive restart replay. */ + TEST_ASSERT_EQUAL_UINT64_MESSAGE(worker_reported_finish_time_s - 60, + (uint64_t)j2_finfail->job.finish_time, + "bug-1747: the recovered finish_time of a finished-failure must " + "be the WORKER-reported time, not replay-time time(NULL)"); TEST_ASSERT_NOT_NULL_MESSAGE(j2_finfail->job.exit_info, "bug-1754: a finished-failure's worker-reported exit code must " "survive restart replay in job.exit_info"); diff --git a/src/include/persist.h b/src/include/persist.h index d1c81f0d..d9c6b87a 100644 --- a/src/include/persist.h +++ b/src/include/persist.h @@ -1523,17 +1523,18 @@ int persist_submit_job_start_fact(persist_t* p, uint64_t jobid, int state, int persist_submit_job_finish_fact(persist_t* p, uint64_t jobid, int state, uint64_t finish_time, int exit_code); -/* bug-1754: WAL_JOB_FAIL's deferred-apply sibling of +/* bug-1754/bug-1747: WAL_JOB_FAIL's deferred-apply sibling of * persist_submit_job_fact_ex() -- header {jobid, 0, WAL_JOB_FAIL_STAGE_FLAG - * | stage} followed by a fixed int32_t code (job_failinfo_t.code). A worker - * reports every nonzero job exit as a FAIL, so for a MAIN-stage failure - * `code` is the job's real exit code; apply_job_fail_exit_code() (job.c) - * adopts it into job.exit_info at both apply seams. A payload of exactly - * sizeof(wal_jobstate_t) (any WAL_JOB_FAIL entry written before this fix) - * carries no code and leaves exit_info untouched. Returns the local-append - * rc, same contract as persist_submit_job_fact(). */ + * | stage} followed by a fixed int32_t code (job_failinfo_t.code) and a + * fixed uint64_t finish_time (seconds). A worker reports every nonzero job + * exit as a FAIL, so for a MAIN-stage failure `code` is the job's real exit + * code; apply_job_fail_exit_code() (job.c) adopts it into job.exit_info and + * both apply seams adopt finish_time instead of apply-time time(NULL). + * Older payloads decode by length: exactly sizeof(wal_jobstate_t) (before + * bug-1754) carries neither; header + code (bug-1754) carries no time. + * Returns the local-append rc, same contract as persist_submit_job_fact(). */ int persist_submit_job_fail_fact(persist_t* p, uint64_t jobid, uint32_t stage, - int code); + int code, uint64_t finish_time); /* bug-1679: fire XCE_CONTROLLER_HOOK_JOB's HOOK_DETAIL_JOB_UPDATE AFTER_EVENT * for a job whose durable WAL fact the caller has ALREADY appended itself diff --git a/src/include/wal_types.h b/src/include/wal_types.h index c00f17df..46f200ad 100644 --- a/src/include/wal_types.h +++ b/src/include/wal_types.h @@ -45,10 +45,11 @@ typedef struct { * markers below. */ #define WAL_JOB_FAIL_STAGE_FLAG 0x80000000u /* WAL_JOB_FAIL: _pad = WAL_JOB_FAIL_STAGE_FLAG | job_failinfo_t.stage, - * optionally followed by an int32_t job_failinfo_t.code (bug-1754). - * Apply time reconstructs a minimal job_failinfo_t from {jobid, stage, - * code} and calls the real apply_job_fail_transition() against current - * state, then apply_job_fail_exit_code() when the code is present. */ + * optionally followed by an int32_t job_failinfo_t.code (bug-1754) and a + * uint64_t finish_time in seconds (bug-1747). Apply time reconstructs a + * minimal job_failinfo_t from {jobid, stage, code} and calls the real + * apply_job_fail_transition() against current state, then + * apply_job_fail_exit_code() and adopts finish_time when present. */ #define WAL_JOB_UPDATE_POSTDONE_MARK 1u /* WAL_JOB_UPDATE: _pad = WAL_JOB_UPDATE_POSTDONE_MARK marks a postdone * merge-fact (`state` is unused/0) — apply time calls