Skip to content

stop: rip out expensive task tracking#59647

Merged
craig[bot] merged 1 commit intocockroachdb:masterfrom
tbg:stopper-lightweight
Feb 3, 2021
Merged

stop: rip out expensive task tracking#59647
craig[bot] merged 1 commit intocockroachdb:masterfrom
tbg:stopper-lightweight

Conversation

@tbg
Copy link
Copy Markdown
Member

@tbg tbg commented Feb 1, 2021

First commit was put up for PR separately, ignore it here.


We are likely going to invest more in the stopper-conferred
observability in the near future as part of initiatives such as #58164,
but the task tracking that has been a part of the stopper since near
its conception has not proven to be useful in practice, while at the
same time raising concern about stopper use in hot paths.

When shutting down a running server, we don't particularly care about leaking
goroutines (as the process will end anyway). In tests, we want to ensure
goroutine hygiene, but if a test hangs during Stop, it is easier to look at
the stacks to find out why than to consult the task map.

Together, this left little reason to do anything more complicated than
what's left after this commit: we keep track of the running number of
tasks, and wait until this drops to zero.

With this change in, we should feel comfortable using the stopper
extensively and, for example, ensuring that any CRDB goroutine is
anchored in a Stopper task; this is the right approach for test flakes
such as in #51544 and makes sense for all of the reasons mentioned in
issue #58164 as well.

In a future change, we should make the Stopper more configurable and,
through this configurability, we could in principle bring a version of
the task map back (in debug builds) without backing it into the stopper,
though I don't anticipate that we'll want to.

Closes #52894.

Release note: None

@cockroach-teamcity
Copy link
Copy Markdown
Member

This change is Reviewable

@tbg tbg requested review from angelapwen, irfansharif, knz and nvb February 1, 2021 15:18
Copy link
Copy Markdown
Contributor

@irfansharif irfansharif left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There's a "fatal error: concurrent map iteration and map write" race condition tripping up the build. Using profiler labels to figure out where we're waiting around rather than registering tasks with the stopper makes sense. Was that the original motivation behind the heavy-weight task tracking?

}
return false
}() {
log.Infof(ctx, "quiescing")
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Instead of this if func() {...} structure, if all we're doing is logging when quiescing for the first time, something like the following would be clearer:

func() {
  // ...
  // log when needed
}()

Copy link
Copy Markdown
Contributor

@nvb nvb left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reviewable status: :shipit: complete! 0 of 0 LGTMs obtained (waiting on @angelapwen, @irfansharif, @knz, and @tbg)


pkg/util/stop/stopper.go, line 240 at r2 (raw file):

}

func (s *Stopper) refuseRLocked() bool {

nit: give this guy a comment. What is it refusing?


pkg/util/stop/stopper.go, line 309 at r2 (raw file):

// Returns an error to indicate that the system is currently quiescing and
// function f was not called.
func (s *Stopper) RunTask(ctx context.Context, taskName string, f func(context.Context)) error {

Do we want to keep taking the taskName? I guess it doesn't hurt.


pkg/util/stop/stopper.go, line 433 at r2 (raw file):

	s.mu.RLock()
	defer s.mu.RUnlock()
	atomic.AddInt32(&s.mu.numTasks, -1)

Do we need to protect numTasks with the RLock? Seems like we could just use atomics to read it in NumTasks with an atomic.LoadInt32.


pkg/util/stop/stopper.go, line 440 at r2 (raw file):

	s.mu.RLock()
	defer s.mu.RUnlock()
	return int(s.mu.numTasks)

This looks wrong. We either need the exclusive lock to read without an atomic load, or we need an atomic load, in which case, why the lock at all?

Related to the previous comment.


pkg/util/stop/stopper.go, line 536 at r2 (raw file):

Previously, irfansharif (irfan sharif) wrote…

Instead of this if func() {...} structure, if all we're doing is logging when quiescing for the first time, something like the following would be clearer:

func() {
  // ...
  // log when needed
}()

Is the idea to avoid the log under the exclusive lock?


pkg/util/stop/stopper.go, line 544 at r2 (raw file):

	s.mu.qCancels = nil

	for s.mu.numTasks > 0 {

Can we read this without a lock and without an atomic load?

@tbg tbg force-pushed the stopper-lightweight branch from 99c7528 to 60366d5 Compare February 2, 2021 08:32
@tbg tbg requested a review from irfansharif February 2, 2021 08:37
Copy link
Copy Markdown
Member Author

@tbg tbg left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Was that the original motivation behind the heavy-weight task tracking?

No, profiler labels didn't even exist then. I think the original intention was that the stopper would be orchestrating a node-wide drain process cleanly and that we'd need deep visibility into it. But that hasn't at all become true, the stopper is really just supposed to tear things down as quickly as possible without leaking goroutines, that's pretty much it, and if it fails to do so it's a bug and will need staring at goroutine dumps anyway.

That said, I have been looking into improving our use of profiler labels in CPU and goroutine profiles with the goal of making CPU profiles a useful tool for assigning blame for CPU usage. Concretely, SREs see a CPU-pegged cluster/node, let them find the app, user, or stmt that does it.

Thanks for the reviews, and sorry about the shoddy PR. Should be better now :)

Reviewable status: :shipit: complete! 0 of 0 LGTMs obtained (waiting on @angelapwen, @irfansharif, and @knz)


pkg/util/stop/stopper.go, line 309 at r2 (raw file):

Previously, nvanbenschoten (Nathan VanBenschoten) wrote…

Do we want to keep taking the taskName? I guess it doesn't hurt.

I've intentionally stayed away from taskName so far, though I think it should ultimately go. What I think will replace it is profiler labels. For example, all goroutines associated to a client session should have the goroutine label for that (with propagation across RPC boundaries). Something like the task name is easy to remove but hard to add back, so I'll wait until that actually materializes.


pkg/util/stop/stopper.go, line 433 at r2 (raw file):

Previously, nvanbenschoten (Nathan VanBenschoten) wrote…

Do we need to protect numTasks with the RLock? Seems like we could just use atomics to read it in NumTasks with an atomic.LoadInt32.

Added a comment on the field:

	// _numTasks is the number of active tasks. It is accessed atomically
	// via addTask() under the read lock for task acquisition. We need the
	// read lock to ensure task creation is prohibited atomically with the
	// quiescing or stopping bools set below.

pkg/util/stop/stopper.go, line 536 at r2 (raw file):

Previously, nvanbenschoten (Nathan VanBenschoten) wrote…

Is the idea to avoid the log under the exclusive lock?

That was the idea, but I don't like the looks of this either. I'm now using an AfterFunc to only log the line after 5s, which I think is the right compromise between not logging anything in the normal case, and making sure we can tell that we're stuck during draining if we are.


pkg/util/stop/stopper.go, line 544 at r2 (raw file):

Previously, nvanbenschoten (Nathan VanBenschoten) wrote…

Can we read this without a lock and without an atomic load?

No, I had only half a brain to work with when I posted this PR. Should've queued it for the AM.

Copy link
Copy Markdown
Contributor

@knz knz left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I am personally attached to task names but not the task map. I believe task names give insight into the current process load (once we can inspect the tasks, which will come). I also believe in pprof labels but I think these serve a different need.

Reviewed 1 of 2 files at r2, 1 of 1 files at r3.
Reviewable status: :shipit: complete! 0 of 0 LGTMs obtained (waiting on @angelapwen and @irfansharif)

@tbg tbg force-pushed the stopper-lightweight branch from 60366d5 to fd1a012 Compare February 3, 2021 13:15
Copy link
Copy Markdown
Contributor

@nvb nvb left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reviewed 1 of 2 files at r4.
Reviewable status: :shipit: complete! 0 of 0 LGTMs obtained (waiting on @angelapwen, @irfansharif, @knz, and @tbg)


pkg/util/stop/stopper.go, line 309 at r2 (raw file):

Previously, tbg (Tobias Grieger) wrote…

I've intentionally stayed away from taskName so far, though I think it should ultimately go. What I think will replace it is profiler labels. For example, all goroutines associated to a client session should have the goroutine label for that (with propagation across RPC boundaries). Something like the task name is easy to remove but hard to add back, so I'll wait until that actually materializes.

👍 that sounds like the right approach.


pkg/util/stop/stopper.go, line 433 at r2 (raw file):

Previously, tbg (Tobias Grieger) wrote…

Added a comment on the field:

	// _numTasks is the number of active tasks. It is accessed atomically
	// via addTask() under the read lock for task acquisition. We need the
	// read lock to ensure task creation is prohibited atomically with the
	// quiescing or stopping bools set below.

But do we need the read lock in runPostlude() or in NumTasks()? As you mention in that comment, the read lock ensures that task creation is prohibited atomically with the quiescing or stopping bools set below.


pkg/util/stop/stopper.go, line 437 at r4 (raw file):

	s.mu.RLock()
	defer s.mu.RUnlock()
	return int(s.addTaskRLocked(0))

This seems like an anti-pattern. An atomic.AddInt32(0) is very different than an atomic.LoadInt32() at the microarchitecture level.

We are likely going to invest more in the stopper-conferred
observability in the near future as part of initiatives such as cockroachdb#58164,
but the task tracking that has been a part of the stopper since near
its conception has not proven to be useful in practice, while at the
same time raising concern about stopper use in hot paths.

When shutting down a running server, we don't particularly care about
leaking goroutines (as the process will end anyway). In tests, we want
to ensure goroutine hygiene, but if a test hangs during `Stop`, it is easier to
look at the stacks to find out why than to consult the task map.

Together, this left little reason to do anything more complicated than
what's left after this commit: we keep track of the running number of
tasks, and wait until this drops to zero.

With this change in, we should feel comfortable using the stopper
extensively and, for example, ensuring that any CRDB goroutine is
anchored in a Stopper task; this is the right approach for test flakes
such as in cockroachdb#51544 and makes sense for all of the reasons mentioned in
issue cockroachdb#58164 as well.

In a future change, we should make the Stopper more configurable and,
through this configurability, we could in principle bring a version of
the task map back (in debug builds) without backing it into the stopper,
though I don't anticipate that we'll want to.

Closes cockroachdb#52894.

Release note: None
@tbg tbg force-pushed the stopper-lightweight branch from fd1a012 to 05c5a74 Compare February 3, 2021 19:46
@tbg tbg requested a review from knz February 3, 2021 19:47
Copy link
Copy Markdown
Member Author

@tbg tbg left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the reviews!

bors r=knz

Reviewable status: :shipit: complete! 0 of 0 LGTMs obtained (waiting on @angelapwen, @irfansharif, and @knz)


pkg/util/stop/stopper.go, line 433 at r2 (raw file):

Previously, nvanbenschoten (Nathan VanBenschoten) wrote…

But do we need the read lock in runPostlude() or in NumTasks()? As you mention in that comment, the read lock ensures that task creation is prohibited atomically with the quiescing or stopping bools set below.

Oh, that's a good call. No, not needed. Fixed.


pkg/util/stop/stopper.go, line 437 at r4 (raw file):

Previously, nvanbenschoten (Nathan VanBenschoten) wrote…

This seems like an anti-pattern. An atomic.AddInt32(0) is very different than an atomic.LoadInt32() at the microarchitecture level.

NumTasks doesn't need to be fast, so I don't know about the anti-pattern (isn't premature optimization an anti-pattern?), but I'm with you in spirit, done.

@craig
Copy link
Copy Markdown
Contributor

craig bot commented Feb 3, 2021

Build succeeded:

@craig craig bot merged commit cb9d41c into cockroachdb:master Feb 3, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

5 participants