Skip to content

waitForValidStateForPrimary timing out once leaves the volume without a filesystem for good: initialization is reported to the controller before mkfs runs #526

Open

Description

@lexfrei

A satellite that misses the 2000 ms HAS_VALID_STATE_FOR_PRIMARY_TIMEOUT window once ends up with a resource that LINSTOR reports as created, DRBD reports UpToDate on every replica, and whose PVC binds normally. There is no filesystem on it, and nothing in the stack ever retries the step that was skipped, so every mount attempt fails with wrong fs type, bad option, bad superblock. I have two occurrences from CI, five days apart, on 1.33.3.

Why it is permanent

In runPostInitializationIfNeeded (DrbdLayer.java at v1.33.3, L948-L990) the controller is told the volume is initialized before the mkfs branch is entered:

if (!initializedVlmNrList.isEmpty())
{
    sendNotifyCtrlVlmNrsWereInitialized(drbdRscDataRef, initializedVlmNrList);

    // TODO we should move the mkfs outside of the devMgr, but that is a different issue/MR
    Resource rsc = drbdRscDataRef.getAbsResource();
    if (MkfsUtils.needsToCreateFs(rsc, workerCtx))
    {
        waitForValidStateForPrimary(drbdRscDataRef);   // throws here

On that notification the controller sets the flag (VlmDfnInternalCallHandler.java:144 at v1.33.3):

vlmDfnFlags.enableFlags(apiCtx, VolumeDefinition.Flags.DRBD_INITIALIZED);

and every later device-manager pass enters through hasLocalStltWonUpToDateRace (DrbdLayer.java:1572-1583):

// if DRBD_INITIALIZED is set, the race is over. It does not matter if we won back then or not.
if (!vlmDfn.getFlags().isSet(workerCtx, VolumeDefinition.Flags.DRBD_INITIALIZED))

So initializedVlmNrList comes back empty and the whole block, mkfs included, is skipped for good. Nothing re-arms it: the satellite never re-enters the block, and the CSI driver retries mount, not mkfs, because the filesystem is LINSTOR's to create (FileSystem/Type on the volume definition). The controller log confirms the notification went out exactly once: Ignoring notifySetUpToDate appears zero times in both occurrences.

Occurrence 1

2026-08-15, resource pvc-047048c2-333a-484f-96c1-56f870b59f65, three nodes (srv1, srv2, srv3), ZFS storage pool, autoPlace: 3, FileSystem/Type = ext4. Single provisioning attempt, no retries involved:

09:06:14  controller  Resource definition created
09:06:17  srv3        ErrorReport-6A802B26-E4EA0-000000
                      StorageException: Device did not get ready within 2000ms
                      waitForValidStateForPrimary   DrbdLayer:1011
                      runPostInitializationIfNeeded DrbdLayer:971
                      adjustDrbd                    DrbdLayer:934
                      processResource               DrbdLayer:284
09:06:21  controller  ACR: Notified node 'srv3' that volume(s) ... [0] is initialized
09:06:23  controller  ACR: Created resource ... on 'srv1'
09:06:27  controller  ACR: Created resource ... on 'srv2'
09:06:30  controller  ACR: Created resource ... on 'srv3'
09:06:39  srv2        mount: wrong fs type, bad option, bad superblock on /dev/drbd1001
   ...    srv2        48 identical attempts, last at 09:24:16

The volume definition ends up carrying Linstor/Drbd/InitialUptoDateOn = SRV3 as if the initialization had succeeded.

Occurrence 2

2026-08-20, resource pvc-8eba13fa-4d2b-4f74-b746-3238af6d8981, same cluster shape. ErrorReport-6A86C809-E4EA0-000000, node srv3, identical stack. Same aftermath: Notified node 'srv3' ... is initialized one second after the exception, replicas created on srv1 and srv2, then 44 mount failures on /dev/drbd1000 starting 09:34:19.

This volume had been through seven earlier provisioning cycles that were rolled back for an unrelated placement reason, which gives a healthy control in the same log: each of those seven cycles shows the promotion, and the eighth, surviving one does not.

How to tell such a volume apart

The one-shot promotion is visible in the kernel log, so the difference between "slow volume" and "volume that will never mount" is a grep for role( Secondary -> Primary ) per node:

Occurrence 1, pvc-047048c2:
  srv3 (first replica / InitialUptoDateOn)   0
  srv2 (node running the pod)               48   <- one per mount retry
  srv1                                       0

Occurrence 2, pvc-8eba13fa:
  srv3 (first replica / InitialUptoDateOn)   7   <- the 7 rolled-back cycles, 0 in the surviving one
  srv1 (node running the pod)               44   <- one per mount retry
  srv2                                       0

A healthy cycle on the initializing node, promotion about 40 ms after attach:

09:32:14.670  disk( Attaching -> UpToDate ) [attach]
09:32:14.711  role( Secondary -> Primary ) [primary]
09:32:14.827  role( Primary -> Secondary ) [secondary]

The failing cycle has the attach and nothing else:

09:33:21.896  disk( Attaching -> UpToDate ) [attach]
09:33:21.900  attached to current UUID: 31D4AD0C26CD51EA
09:33:22.644  disk( UpToDate -> Detaching ) [down]

The peers that join afterwards sync from the blank device and agree with it:

srv1  Began resync as SyncTarget (will sync 0 KB [0 bits set])
srv1  Resync done (total 1 sec; paused 0 sec; 0 K/sec)
srv1  disk( Inconsistent -> UpToDate ) [resync-finished]

Zero bits is correct, nothing was ever written. linstor resource list shows UpToDate on all three, Conns: Ok, and the volume is unusable.

What the timeout waits for

ReadyForPrimaryNotifier.hasValidStateForPrimary waits for every volume of the resource to leave Attaching, driven by DrbdStateTracker.OBS_DISK events, and HAS_VALID_STATE_FOR_PRIMARY_TIMEOUT is a hard-coded 2000 ms (DrbdLayer.java:100) with no property behind it. In occurrence 2 the disk( Attaching -> UpToDate ) transition landed at 09:33:21.896 and the exception is stamped 09:33:21, so the transition arrived just outside the window. Why the attach was slow is environment-specific (a busy CI node will occasionally miss a two-second budget) and I am not claiming that part is a LINSTOR problem. What I am reporting is that missing it once is fatal and silent.

Suggested direction

Sending sendNotifyCtrlVlmNrsWereInitialized only after MkfsUtils.makeFileSystemOnMarked has returned would make the failure recoverable on the next device-manager pass, since DRBD_INITIALIZED would still be unset and the block would be re-entered. If the notification has to stay where it is, a separate per-volume "filesystem created" marker gated the same way would do the same. Raising or exposing the 2000 ms constant only reduces how often this is reached; it does not help once it is reached.

Possibly related by symptom: #515 (fresh CSI volumes stay Inconsistent because the initial-sync skip never runs). Different trigger and code path, same end state of a bound volume that cannot be mounted.

Environment

  • linstor-server 1.33.3, satellite built from the v1.33.3 tag. All four stack frames land on the expected statements at that tag: DrbdLayer.java:1011 is the throw new StorageException, :971 the waitForValidStateForPrimary call, :934 the runPostInitializationIfNeeded call, :284 the adjustDrbd call.
  • linstor-csi v1.11.2, piraeus-operator v2.10.2, Kubernetes on Talos, ZFS storage pools, layerList: drbd storage, autoPlace: 3 on three nodes.
  • The image is a downstream build of v1.33.3 with five local patches. None touches DrbdLayer.java, MkfsUtils, ReadyForPrimaryNotifier or VlmDfnInternalCallHandler. One of them, retry-secondary-after-mkfs, sits nearby: it wraps DrbdAdm.DrbdPrimary.close() so the demotion after mkfs retries on Device is held open by someone. That code runs only after waitForValidStateForPrimary has returned and mkfs has run, so it is not in this failure path, but I am naming it so the build is not treated as stock.
  • Still present on master as of 1.35.0-rc.1: same constant, same ordering of the notification and the mkfs branch.

I can supply the full error reports, the controller log and the kernel logs from all three nodes for either occurrence.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions