storage: improve disk stall error message

[shermanCRL]

A client recently saw “disk stall” errors that led them to assume a hardware problem, and so they took disks offline, which led to further problems.

It appears that several situations can lead to such an error -- hitting the max # of files (1000), or other things. Is it correct that “disk stall” errors can result from distinct underlying situations? If so, is it possible to return different error messages, so users can better troubleshoot?

(If this should be in the Pebble repo, let me know.)

Jira issue: CRDB-8742

Epic CRDB-20293

[mwang1026]

Whoever picks this up, let's do a kickoff where we vet the right UX around what messages to display upon detecting which disk issues

[nicktrav]

I think cockroachlabs/support#1630 also highlighted the need for some disambiguation. In this case it was some way of determining the difference between "slow", "huge write going as fast as it can" and "stalled". We incorrectly assumed the latter, and therefore a hardware issue, which lessened the efficacy of our initial response.

cc: @jbowens @bananabrick

[jbowens]

For cockroachlabs/support#1630, I think it would've been helpful for the logged message to include the length of the write buffer that failed to write within the configured duration.

[joshimhoff]

@jbowens, I have a few Qs for you as TL! I'm taking this over as a starter issue. Looks like cockroachdb/pebble#1672 from @nicktrav adds the op type but not the length of the write buffer. Unless someone tells me not to, I will add the length of the write buffer too, in case of a "sized write", as this will make the starter issue a bit more difficult, which will help me learn storage stuff.

In my starter doc, I see the following comment:

We’d ideally have the same context provided up in Cockroach too.

What is the concrete goal of providing this context into the CRDB layer? That the fatal log message here (

cockroach/pkg/storage/pebble.go

Line 1076 in bfd1b3f

log.Fatalf(ctx, "disk stall detected: pebble unable to write to %s in %.2f seconds",

) includes the same extra context that cockroachdb/pebble#1672 adds to the pebble log?

Also, should I backport these changes into some older CRDB versions?

[jbowens]

I will add the length of the write buffer too, in case of a "sized write"

Sounds good

In my starter doc, I see the following comment:

Mind linking me? I'm not sure off-hand what that comment is referring to.

I think this original issue was created to update the language for the disk stall error to be a little less accusatory towards the hard disks. Maybe something like a "filesystem write stall," plus a comment that it may be a hard disk stall? I think making those changes, plus including the write buffer size should cover it.

cockroach/pkg/storage/pebble.go

Lines 1065 to 1086 in 20b2e81

	DiskSlow: func(info pebble.DiskSlowInfo) {
	maxSyncDuration := maxSyncDurationDefault
	fatalOnExceeded := maxSyncDurationFatalOnExceededDefault
	if p.settings != nil {
	maxSyncDuration = MaxSyncDuration.Get(&p.settings.SV)
	fatalOnExceeded = MaxSyncDurationFatalOnExceeded.Get(&p.settings.SV)
	}
	if info.Duration.Seconds() >= maxSyncDuration.Seconds() {
	atomic.AddInt64(&p.diskStallCount, 1)
	// Note that the below log messages go to the main cockroach log, not
	// the pebble-specific log.
	if fatalOnExceeded {
	log.Fatalf(ctx, "disk stall detected: pebble unable to write to %s in %.2f seconds",
	info.Path, redact.Safe(info.Duration.Seconds()))
	} else {
	log.Errorf(ctx, "disk stall detected: pebble unable to write to %s in %.2f seconds",
	info.Path, redact.Safe(info.Duration.Seconds()))
	}
	return
	}
	atomic.AddInt64(&p.diskSlowCount, 1)
	},

[joshimhoff]

Thanks, @jbowens! All makes sense.

Mind linking me?

Here ya go: https://docs.google.com/document/d/1zgpqbSd1RbCSaDh36Sbd8UgG4XgS8rP41GGhBrFXyRs/edit

Specifically, the below part, which I think is suggesting the context is included in fatal message in the CRDB logs in addition to the pebble logs (as is already partially handled by cockroachdb/pebble#1672):

We’d ideally have the same context provided up in Cockroach too.

[joshimhoff]

I think I get now what the bit from the starter doc was getting at; cockroachdb/pebble#1672 adds more context to DiskSlowInfo but doesn't actually plumb that context into a log file IIUC.

I think I will prob adjust the below CRDB code to call DiskSlowInfo's SafeFormat method; that way, whatever context is available in the pebble layer will be in the CRDB logs:

cockroach/pkg/storage/pebble.go

Lines 1065 to 1086 in 20b2e81

	DiskSlow: func(info pebble.DiskSlowInfo) {
	maxSyncDuration := maxSyncDurationDefault
	fatalOnExceeded := maxSyncDurationFatalOnExceededDefault
	if p.settings != nil {
	maxSyncDuration = MaxSyncDuration.Get(&p.settings.SV)
	fatalOnExceeded = MaxSyncDurationFatalOnExceeded.Get(&p.settings.SV)
	}
	if info.Duration.Seconds() >= maxSyncDuration.Seconds() {
	atomic.AddInt64(&p.diskStallCount, 1)
	// Note that the below log messages go to the main cockroach log, not
	// the pebble-specific log.
	if fatalOnExceeded {
	log.Fatalf(ctx, "disk stall detected: pebble unable to write to %s in %.2f seconds",
	info.Path, redact.Safe(info.Duration.Seconds()))
	} else {
	log.Errorf(ctx, "disk stall detected: pebble unable to write to %s in %.2f seconds",
	info.Path, redact.Safe(info.Duration.Seconds()))
	}
	return
	}
	atomic.AddInt64(&p.diskSlowCount, 1)
	},

[joshimhoff]

Merged #95436 & cockroachdb/pebble#2255. Just put up cockroachdb/pebble#2281. Once that one goes in, I think I'm done with this issue, modulo a quick e2e test plus any branch stuff we might want to do, e.g. backports.

[nicktrav]

@joshimhoff - going to send this one your way, as it's in progress.

[joshimhoff]

Thanks. I'll close this out next next week (I am oncall next week). Got excited with the disagg testing but will be good to close this out.

[joshimhoff]

cockroachdb/pebble#2281