Skip to content

Commit 019a465

Browse files
committed
cephfs: avoid hanging os.Stat() in NodeGetVolumeStats after restart
If a node-plugin pod restarts while the backend (e.g. MDS) is down, NodeGetVolumeStats used to call os.Stat() on the target path immediately after (re)starting the health checker, before the checker had a chance to detect the outage. Since os.Stat() blocks in the kernel on an unresponsive mount, this held the VolumeLock forever and made every later call for that path fail with Aborted. Return early with an "not yet available" condition instead of calling os.Stat() when the checker was just (re)started, for CephFS. Signed-off-by: SanjalKatiyar <sanjaldhir@gmail.com>
1 parent b22ca60 commit 019a465

8 files changed

Lines changed: 3184 additions & 23 deletions

File tree

internal/cephfs/nodeserver.go

Lines changed: 23 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -941,19 +941,38 @@ func (ns *cephfsNodeServer) NodeGetVolumeStats(
941941
// health check first, return without stats if unhealthy
942942
healthy, msg := ns.healthChecker.IsHealthy(volumeID, targetPath)
943943

944-
// If healthy and an error is returned, it means that the checker was not
945-
// started. This could happen when the node-plugin was restarted and the
944+
// If healthy and an error is returned, it either means that the checker
945+
// was not started or it is running but has not completed its
946+
// first health-check cycle yet.
947+
// This could happen when the node-plugin was restarted and the
946948
// volume is already staged and published.
947949
if healthy && msg != nil {
948950
// Start a StatChecker for the mounted targetPath, this prevents
949951
// writing a file in the user-visible location. Ideally a (shared)
950952
// FileChecker is started with the stagingTargetPath, but we can't
951953
// get the stagingPath from the request easily.
952954
// TODO: resolve the stagingPath like rbd.getStagingPath() does
955+
// NOTE: rbd.getStagingPath() uses os.Stat() internally which
956+
// if called synchronously, could block indefinitely.
957+
958+
// Start the background checker but return
959+
// immediately instead of calling os.Stat() on this goroutine.
960+
// If the mount is unresponsive, os.Stat() would block,
961+
// holding the VolumeLock (acquired above) and preventing all future
962+
// calls for this path from reaching isHealthy().
963+
// The background checker will do the stat(), the next periodic
964+
// call will pick up the result (or detect the timeout).
953965
err = ns.healthChecker.StartChecker(req.GetVolumeId(), targetPath, hc.StatCheckerType)
954966
if err != nil {
955967
log.WarningLog(ctx, "failed to start healthchecker: %v", err)
956968
}
969+
970+
return &csi.NodeGetVolumeStatsResponse{
971+
VolumeCondition: &csi.VolumeCondition{
972+
Abnormal: false,
973+
Message: "health checker started, status not yet available",
974+
},
975+
}, nil
957976
}
958977

959978
// !healthy indicates a problem with the volume
@@ -966,7 +985,8 @@ func (ns *cephfsNodeServer) NodeGetVolumeStats(
966985
}, nil
967986
}
968987

969-
// warning: stat() may hang on an unhealthy volume
988+
// warning: reaching here should mean that synchronous os.Stat()
989+
// call is safe and will not indefinitely block/hang
970990
stat, err := os.Stat(targetPath)
971991
if err != nil {
972992
if util.IsCorruptedMountError(err) {

internal/health-checker/checker.go

Lines changed: 24 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -37,8 +37,8 @@ type checker struct {
3737
// timeout contains the delay (interval + timeout)
3838
timeout time.Duration
3939

40-
// mutex protects against concurrent access to healthy, err and
41-
// lastUpdate
40+
// mutex protects against concurrent access to healthy, err,
41+
// lastUpdate and checked
4242
mutex *sync.RWMutex
4343

4444
// current status
@@ -47,6 +47,12 @@ type checker struct {
4747
err error
4848
lastUpdate time.Time
4949

50+
// checked is set to true once runChecker() has completed its first
51+
// health-check cycle (successful or not). This matters for
52+
// checker (re)start scenarios, e.g. following a node-plugin restart
53+
// where the volume was already mounted.
54+
checked bool
55+
5056
// commands is the channel to read commands from; when to stop.
5157
commands chan command
5258

@@ -60,6 +66,7 @@ func (c *checker) initDefaults() {
6066
c.isRunning = false
6167
c.err = nil
6268
c.healthy = true
69+
c.checked = false
6370
c.lastUpdate = time.Now()
6471
c.commands = make(chan command)
6572

@@ -91,12 +98,25 @@ func (c *checker) isHealthy() (bool, error) {
9198
// It is required to check, in case the write or read in the go routine
9299
// is blocked.
93100

94-
delay := time.Since(c.lastUpdate)
95-
if delay > (c.interval + c.timeout) {
101+
c.mutex.RLock()
102+
checked := c.checked
103+
lastUpdate := c.lastUpdate
104+
c.mutex.RUnlock()
105+
106+
delay := time.Since(lastUpdate)
107+
switch {
108+
case delay > (c.interval + c.timeout):
96109
c.mutex.Lock()
97110
c.healthy = false
98111
c.err = fmt.Errorf("health-check has not responded for %f seconds", delay.Seconds())
99112
c.mutex.Unlock()
113+
case !checked:
114+
// The first health-check cycle has not completed yet.
115+
// Report this explicitly so that callers do
116+
// not mistake this for a confirmed healthy volume and fall
117+
// through to a fallback that could itself block (e.g. a
118+
// synchronous os.Stat() on an unresponsive mount).
119+
return true, fmt.Errorf("health-check has not completed its first check yet")
100120
}
101121

102122
// read lock to get consistency between the return values
Lines changed: 75 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,75 @@
1+
/*
2+
Copyright 2026 ceph-csi authors.
3+
4+
Licensed under the Apache License, Version 2.0 (the "License");
5+
you may not use this file except in compliance with the License.
6+
You may obtain a copy of the License at
7+
8+
http://www.apache.org/licenses/LICENSE-2.0
9+
10+
Unless required by applicable law or agreed to in writing, software
11+
distributed under the License is distributed on an "AS IS" BASIS,
12+
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13+
See the License for the specific language governing permissions and
14+
limitations under the License.
15+
*/
16+
17+
package healthchecker
18+
19+
import (
20+
"testing"
21+
"time"
22+
)
23+
24+
func TestCheckerNotYetChecked(t *testing.T) {
25+
t.Parallel()
26+
27+
c := &checker{}
28+
c.initDefaults()
29+
30+
healthy, err := c.isHealthy()
31+
if !healthy || err == nil {
32+
t.Errorf("expected (true, error) for a checker that has not completed its first check, got (%t, %v)",
33+
healthy, err)
34+
}
35+
}
36+
37+
func TestCheckerStuckFirstCheckEventuallyTimesOut(t *testing.T) {
38+
t.Parallel()
39+
40+
c := &checker{}
41+
c.initDefaults()
42+
c.interval = time.Millisecond
43+
c.timeout = time.Millisecond
44+
45+
c.mutex.Lock()
46+
c.lastUpdate = time.Now().Add(-time.Hour)
47+
c.mutex.Unlock()
48+
49+
healthy, err := c.isHealthy()
50+
if healthy || err == nil {
51+
t.Errorf("expected (false, error) for a checker whose first check is stuck and overdue, got (%t, %v)",
52+
healthy, err)
53+
}
54+
}
55+
56+
func TestCheckerConfirmedHealthyStillExpires(t *testing.T) {
57+
t.Parallel()
58+
59+
c := &checker{}
60+
c.initDefaults()
61+
c.interval = time.Millisecond
62+
c.timeout = time.Millisecond
63+
64+
c.mutex.Lock()
65+
c.checked = true
66+
c.healthy = true
67+
c.err = nil
68+
c.lastUpdate = time.Now().Add(-time.Hour)
69+
c.mutex.Unlock()
70+
71+
healthy, err := c.isHealthy()
72+
if healthy || err == nil {
73+
t.Errorf("expected (false, error) for a checker that stopped reporting, got (%t, %v)", healthy, err)
74+
}
75+
}

internal/health-checker/filechecker.go

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -52,6 +52,7 @@ func newFileChecker(dir string) ConditionChecker {
5252
err := fc.writeTimestamp(now)
5353
if err != nil {
5454
fc.mutex.Lock()
55+
fc.checked = true
5556
fc.healthy = false
5657
fc.err = err
5758
fc.mutex.Unlock()
@@ -62,6 +63,7 @@ func newFileChecker(dir string) ConditionChecker {
6263
ts, err := fc.readTimestamp()
6364
if err != nil {
6465
fc.mutex.Lock()
66+
fc.checked = true
6567
fc.healthy = false
6668
fc.err = err
6769
fc.mutex.Unlock()
@@ -72,6 +74,7 @@ func newFileChecker(dir string) ConditionChecker {
7274
// verify that the written timestamp is read back
7375
if now.Compare(ts) != 0 {
7476
fc.mutex.Lock()
77+
fc.checked = true
7578
fc.healthy = false
7679
fc.err = errors.New("timestamp read from file does not match what was written")
7780
fc.mutex.Unlock()
@@ -81,6 +84,7 @@ func newFileChecker(dir string) ConditionChecker {
8184

8285
// run health check, write a timestamp to a file, read it back
8386
fc.mutex.Lock()
87+
fc.checked = true
8488
fc.healthy = true
8589
fc.err = nil
8690
fc.lastUpdate = ts

internal/health-checker/filechecker_test.go

Lines changed: 11 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -30,7 +30,7 @@ func TestFileChecker(t *testing.T) {
3030
if !ok {
3131
t.Errorf("failed to convert fc to *fileChecker: %v", fc)
3232
}
33-
checker.interval = time.Second * 5
33+
checker.interval = time.Second * 3
3434

3535
// start the checker
3636
checker.start()
@@ -41,9 +41,18 @@ func TestFileChecker(t *testing.T) {
4141
t.Error("checker failed to start")
4242
}
4343

44+
// before the checker has completed its first check cycle
45+
healthy, msg := checker.isHealthy()
46+
if !healthy || msg == nil {
47+
t.Errorf("expected (true, error) before the first tick, got (%t, %v)", healthy, msg)
48+
}
49+
50+
// wait well past the first tick, so the first check has completed.
51+
time.Sleep(checker.interval + time.Second)
52+
4453
for range 10 {
4554
// check health, should be healthy
46-
healthy, msg := checker.isHealthy()
55+
healthy, msg = checker.isHealthy()
4756
if !healthy || msg != nil {
4857
t.Error("volume is unhealthy")
4958
}

internal/health-checker/statchecker.go

Lines changed: 10 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -47,20 +47,18 @@ func newStatChecker(dir string) ConditionChecker {
4747

4848
return
4949
case now := <-ticker.C:
50-
_, err := os.Stat(sc.dirname)
51-
if err != nil {
52-
sc.mutex.Lock()
53-
sc.healthy = false
54-
sc.err = err
55-
sc.mutex.Unlock()
56-
57-
continue
58-
}
50+
_, statErr := os.Stat(sc.dirname)
5951

6052
sc.mutex.Lock()
61-
sc.healthy = true
62-
sc.err = nil
63-
sc.lastUpdate = now
53+
sc.checked = true
54+
if statErr != nil {
55+
sc.healthy = false
56+
sc.err = statErr
57+
} else {
58+
sc.healthy = true
59+
sc.err = nil
60+
sc.lastUpdate = now
61+
}
6462
sc.mutex.Unlock()
6563
}
6664
}

internal/health-checker/statchecker_test.go

Lines changed: 11 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -30,7 +30,7 @@ func TestStatChecker(t *testing.T) {
3030
if !ok {
3131
t.Errorf("failed to convert fc to *fileChecker: %v", sc)
3232
}
33-
checker.interval = time.Second * 5
33+
checker.interval = time.Second * 3
3434

3535
// start the checker
3636
checker.start()
@@ -41,9 +41,18 @@ func TestStatChecker(t *testing.T) {
4141
t.Error("checker failed to start")
4242
}
4343

44+
// before the checker has completed its first check cycle
45+
healthy, msg := checker.isHealthy()
46+
if !healthy || msg == nil {
47+
t.Errorf("expected (true, error) before the first tick, got (%t, %v)", healthy, msg)
48+
}
49+
50+
// wait well past the first tick, so the first check has completed.
51+
time.Sleep(checker.interval + time.Second)
52+
4453
for i := range 10 {
4554
// check health, should be healthy
46-
healthy, msg := checker.isHealthy()
55+
healthy, msg = checker.isHealthy()
4756
if !healthy || msg != nil {
4857
t.Errorf("volume is unhealthy after %d tries", i+1)
4958
}

0 commit comments

Comments
 (0)