release-26.2: roachtest: import/pause/distmerge=true/nodes=4 failed

[cockroach-teamcity]

roachtest.import/pause/distmerge=true/nodes=4 failed with artifacts on release-26.2 @ dbd0d4d308582d2a46abe3beb4c9c64dbc3fe0ea:

Failed with:

(test_runner.go:2684).func1: task ``task-2`` returned error: import tpch/orders: pausing job 1164246449804017665: pq: job 1164246449804017665: job with state failed cannot be requested to be paused
test artifacts and logs in: /artifacts/import/pause/distmerge=true/nodes=4/run_1

Cluster Node to Ip Mapping:

Node	Public IP	Private IP
teamcity-21298673-1775368993-01-n4cpu4-0001	34.23.240.192	10.142.2.194
teamcity-21298673-1775368993-01-n4cpu4-0002	34.23.40.110	10.142.2.198
teamcity-21298673-1775368993-01-n4cpu4-0003	35.243.136.62	10.142.2.193
teamcity-21298673-1775368993-01-n4cpu4-0004	35.231.40.158	10.142.2.197

Parameters:

• arch=amd64
• cloud=gce
• coverageBuild=false
• cpu=4
• diskCount=0
• encrypted=false
• metamorphicLeases=expiration
• metamorphicWriteBuffering=true
• runtimeAssertionsBuild=false

Help

See: roachtest README

See: How To Investigate (internal)

See: Grafana

This test on roachdash | Improve this report!

Jira issue: CRDB-62528

[celiala]

/investigate

[github-actions]

Investigation: import/pause/distmerge=true/nodes=4

Investigated failure: #167549
Failure SHA: dbd0d4d308582d2a46abe3beb4c9c64dbc3fe0ea
Confidence: high

What This Test Does

The import/pause roachtest starts an IMPORT INTO job (importing a TPC-H dataset), then pauses/resumes it multiple times (2-4 cycles with random timing), and verifies the job completes successfully. The distmerge=true variant enables the bulkio.import.distributed_merge.enabled cluster setting.

Where the Failure Occurs

The import job itself fails with an assertion failure in tabledesc.(*Mutable).InitializeImport:

Import in progress with start time 1775370235024908516

This assertion fires because ImportStartWallTime is already non-zero when InitializeImport is called a second time. The job transitions through running → reverting → failed. When the test then tries to PAUSE JOB, it gets: job with state failed cannot be requested to be paused.

Analysis

Likely cause (high confidence): Race condition between bindTableDescImportProperties and SetDetails during pause/resume

The root cause is a product bug in the import resume path. Here is the sequence:

1. First run on n1 (06:23:54): The import job starts and enters the if details.Walltime == 0 block in import_job.go:327. It:

   • Sets details.Walltime (line 330)
   • Calls bindTableDescImportProperties which writes ImportStartWallTime to the table descriptor (line 336)
   • Then should persist the walltime via r.job.NoTxn().SetDetails(ctx, details) (line 340)

2. Pause at 06:23:55.033: The test issues PAUSE JOB just ~9ms after the import event is logged. The pause request arrives between the bindTableDescImportProperties (which already wrote ImportStartWallTime to the table descriptor) and the SetDetails call (which would have persisted Walltime in the job record). The pause interrupts the job execution.

3. Resume at 06:24:08: The job is resumed. It gets re-adopted by n3 at 06:24:25.

4. Second run on n3 (06:24:25): When Resume() runs again, details.Walltime is still 0 in the job record (because SetDetails never completed). So it enters the if details.Walltime == 0 block again and calls bindTableDescImportProperties → InitializeImport. But the table descriptor already has ImportStartWallTime set from step 1, so InitializeImport fires the assertion: "Import in progress with start time %v".

5. The assertion error causes the job to transition to reverting → failed.

6. Meanwhile, the test is waiting to pause the job again (pause 2/4). When it tries PAUSE JOB, the job is already in failed state, producing the error: job with state failed cannot be requested to be paused.

Secondary issue in the test (low confidence, minor): The test's pre-pause status check at import.go:809 only checks for "succeeded" and doesn't handle "failed", "reverting", or other terminal states. This means even without the race, any transient job failure would cause a confusing error. However, this is a minor hardening issue — the primary fix needs to be in the import code.

Potential fix: The bindTableDescImportProperties call and SetDetails should be done atomically, or InitializeImport should be made idempotent (i.e., allow re-setting the same walltime or any walltime if the existing value matches what's expected). Alternatively, the Walltime should be persisted in the job details first, or the table descriptor's ImportStartWallTime should be checked and reset during the resume path before calling InitializeImport.

Related Issues and PRs

This is a recurring failure. All of the following are the same root cause:

Issue	Branch	Date	Error
#167549	release-26.2	2026-04-06	job with state failed cannot be requested to be paused
#167195	release-26.2	2026-04-01	unexpectedly found job in state failed
#167194	master	2026-04-01	unexpectedly found job in state failed
#166988	master	2026-03-30	same
#166959	release-26.2	2026-03-30	state failed / state reverting
#166499	release-26.2	2026-03-24	same
#166403	master	2026-03-23	same
#166262	release-26.2	2026-03-20	same
#165781	master	2026-03-17	same

All closed issues were closed as duplicates. No fix PR has been found. The import/pause test was introduced in commit 1faa18df6a5 on 2026-01-14.

Timeline

• 2022-08-04: ImportStartWallTime and InitializeImport assertion added in commit 5c16ad448ea.
• 2026-01-14: import/pause roachtest added in commit 1faa18df6a5.
• 2026-03-17 onward: Recurring failures of import/pause/distmerge=true/nodes=4 on both master and release-26.2.
• 2026-04-06: Latest failure (this issue).

Detailed evidence and investigation notes

Log Excerpts

test.log timeline (all times UTC):

06:23:39 - Starting import test 'pause' with dataset: tpch/orders
06:23:39 - importing tpch/orders
06:23:39 - will pause/resume job 1164246449804017665 4 times
06:23:54 - pausing job (pause 1/4)
06:24:00 - job paused, keeping paused for 8s
06:24:08 - resuming job (pause 1/4)
06:24:08 - job resumed successfully
06:24:52 - pausing job (pause 2/4)    ← THIS IS WHERE IT FAILS
06:24:52 - FAILURE: job with state failed cannot be requested to be paused

Node 1 log (first run):

06:23:54 - job 1164246449804017665: resuming execution
06:23:55.024 - import event logged (status: running)
06:23:55.033 - pause requested ← 9ms after import start, between descriptor write and SetDetails
06:23:55.053 - adoption completed with error: cannot update progress on pause-requested job
06:23:59 - job paused
06:24:08 - state changed to: running (resumed)

Node 3 log (second run, after resume):

06:24:25.072 - job 1164246449804017665: resuming execution
06:24:25.087 - IMPORT job: stepping through state running
06:24:25.121 - ASSERTION FAILURE: Import in progress with start time 1775370235024908516
    at tabledesc.(*Mutable).InitializeImport (table_desc.go:215)
    at bindTableDescImportProperties.func1 (import_job.go:632)
    at importResumer.Resume (import_job.go:336)
06:24:25.135 - state changed to: reverting
06:24:25.397 - state changed to: failed

Code References

The critical code path in import_job.go:327-342:

if details.Walltime == 0 {
    details.Walltime = p.ExecCfg().Clock.Now().WallTime
    details.Table.Desc.ImportStartWallTime = details.Walltime
    details.Tables[0].Desc.ImportStartWallTime = details.Walltime

    // THIS writes ImportStartWallTime to the table descriptor:
    if err := bindTableDescImportProperties(ctx, p, table.Desc.ID, details.Walltime); err != nil {
        return err
    }
    // THIS persists Walltime to the job record — but may not complete if paused:
    if err := r.job.NoTxn().SetDetails(ctx, details); err != nil {
        return err
    }
}

The assertion in table_desc.go:213-218:

func (desc *Mutable) InitializeImport(startWallTime int64) error {
    if desc.ImportStartWallTime != 0 {
        return errors.AssertionFailedf("Import in progress with start time %v", desc.ImportStartWallTime)
    }
    desc.ImportStartWallTime = startWallTime
    return nil
}

Things Ruled Out

• Distributed merge specific issue: While all failures are with distmerge=true, the root cause is in the core import resume path (import_job.go), not in distributed merge. The distmerge=true variant may simply make the timing window more likely (e.g., slower startup) or the distmerge=false variant may not have been tested as much with the pause test.
• Test-only bug: While the test could be more resilient (checking for failed state before pausing), the underlying product bug — the non-atomic update of ImportStartWallTime in the descriptor vs. Walltime in job details — is a real correctness issue that could affect production pause/resume of imports.
• Node shutdown / distributed merge resilience (bulkmerge: distributed merge permanently fails when a participating SQL instance goes down #167491): This is a separate issue about distributed merge not handling downed instances well. The import/pause failures are caused by the walltime race, not by node failures.

Other Failure Occurrences

All failures in the thread follow the same pattern:

• Some show job with state failed cannot be requested to be paused (when the test races to pause a failed job)
• Others show unexpectedly found job in state failed or state reverting (when WaitForSucceeded detects the failure)

Both error signatures point to the same root cause: the import job failing due to the InitializeImport assertion after pause/resume.

Tooling Feedback

No tooling issues encountered during this investigation. The TC guest auth artifact download, log searching, and git tools all worked well.

---

Workflow run

Was this investigation helpful? Leave a 👍 or 👎 on this comment.