Skip to content

Commit

Permalink
cli: avoid using background ctx in server start
Browse files Browse the repository at this point in the history
This change ensures that the entire server startup and shutdown logic
operates under a go context that is connected to the main config's
tracer and AmbientCtx (and its log tags, and server identifiers).

Release note: None
  • Loading branch information
knz committed Dec 13, 2021
1 parent d565b79 commit 9f86eb8
Show file tree
Hide file tree
Showing 4 changed files with 42 additions and 23 deletions.
11 changes: 10 additions & 1 deletion pkg/cli/mt_start_sql.go
Original file line number Diff line number Diff line change
Expand Up @@ -75,7 +75,16 @@ func runStartSQL(cmd *cobra.Command, args []string) error {
return err
}

ctx := context.Background()
// Set up a cancellable context for the entire start command.
// The context will be canceled at the end.
ctx, cancel := context.WithCancel(context.Background())
defer cancel()

// The context annotation ensures that server identifiers show up
// in the logging metadata as soon as they are known.
ambientCtx := serverCfg.AmbientCtx
ctx = ambientCtx.AnnotateCtx(ctx)

const clusterName = ""

stopper, err := setupAndInitializeLoggingAndProfiling(ctx, cmd, false /* isServerCmd */)
Expand Down
46 changes: 25 additions & 21 deletions pkg/cli/start.go
Original file line number Diff line number Diff line change
Expand Up @@ -59,6 +59,7 @@ import (
"github.com/cockroachdb/cockroach/pkg/util/tracing"
"github.com/cockroachdb/errors"
"github.com/cockroachdb/errors/oserror"
"github.com/cockroachdb/logtags"
"github.com/cockroachdb/pebble/vfs"
"github.com/cockroachdb/redact"
"github.com/spf13/cobra"
Expand Down Expand Up @@ -407,16 +408,21 @@ func runStart(cmd *cobra.Command, args []string, startSingleNode bool) (returnEr
ctx, cancel := context.WithCancel(context.Background())
defer cancel()

// Set up a tracing span for the start process. We want any logging
// happening beyond this point to be accounted to this start
// context, including logging related to the initialization of
// the logging infrastructure below.
// This span concludes when the startup goroutine started below
// has completed.
// TODO(andrei): we don't close the span on the early returns below.
tracer := serverCfg.Tracer
startupSpan := tracer.StartSpan("server start")
ctx = tracing.ContextWithSpan(ctx, startupSpan)
ambientCtx := serverCfg.AmbientCtx

// Annotate the context, and set up a tracing span for the start process.
//
// The context annotation ensures that server identifiers show up
// in the logging metadata as soon as they are known.
//
// The tracing span is because we want any logging happening beyond
// this point to be accounted to this start context, including
// logging related to the initialization of the logging
// infrastructure below. This span concludes when the startup
// goroutine started below has completed. TODO(andrei): we don't
// close the span on the early returns below.
var startupSpan *tracing.Span
ctx, startupSpan = ambientCtx.AnnotateCtxWithSpan(ctx, "server start")

// Set up the logging and profiling output.
//
Expand Down Expand Up @@ -568,7 +574,7 @@ func runStart(cmd *cobra.Command, args []string, startSingleNode bool) (returnEr
If problems persist, please see %s.`
docLink := docs.URL("cluster-setup-troubleshooting.html")
if !startCtx.inBackground {
log.Ops.Shoutf(context.Background(), severity.WARNING, msg, docLink)
log.Ops.Shoutf(ctx, severity.WARNING, msg, docLink)
} else {
// Don't shout to stderr since the server will have detached by
// the time this function gets called.
Expand Down Expand Up @@ -699,9 +705,8 @@ If problems persist, please see %s.`
// decommission`, or a signal.

// We'll want to log any shutdown activity against a separate span.
shutdownSpan := tracer.StartSpan("server shutdown")
shutdownCtx, shutdownSpan := ambientCtx.AnnotateCtxWithSpan(context.Background(), "server shutdown")
defer shutdownSpan.Finish()
shutdownCtx := tracing.ContextWithSpan(context.Background(), shutdownSpan)

stopWithoutDrain := make(chan struct{}) // closed if interrupted very early

Expand Down Expand Up @@ -764,9 +769,8 @@ If problems persist, please see %s.`
}
// Don't use shutdownCtx because this is in a goroutine that may
// still be running after shutdownCtx's span has been finished.
ac := log.AmbientContext{}
ac.AddLogTag("server drain process", nil)
drainCtx := ac.AnnotateCtx(context.Background())
drainCtx := ambientCtx.AnnotateCtx(context.Background())
drainCtx = logtags.AddTag(drainCtx, "server drain process", nil)

// Perform a graceful drain. We keep retrying forever, in
// case there are many range leases or some unavailability
Expand Down Expand Up @@ -824,7 +828,7 @@ If problems persist, please see %s.`
for {
select {
case <-ticker.C:
log.Ops.Infof(context.Background(), "%d running tasks", stopper.NumTasks())
log.Ops.Infof(shutdownCtx, "%d running tasks", stopper.NumTasks())
case <-stopper.IsStopped():
return
case <-stopWithoutDrain:
Expand Down Expand Up @@ -1063,7 +1067,7 @@ func maybeWarnMemorySizes(ctx context.Context) {
var buf bytes.Buffer
fmt.Fprintf(&buf, "Using the default setting for --cache (%s).\n", cacheSizeValue)
fmt.Fprintf(&buf, " A significantly larger value is usually needed for good performance.\n")
if size, err := status.GetTotalMemory(context.Background()); err == nil {
if size, err := status.GetTotalMemory(ctx); err == nil {
fmt.Fprintf(&buf, " If you have a dedicated server a reasonable setting is --cache=.25 (%s).",
humanizeutil.IBytes(size/4))
} else {
Expand Down Expand Up @@ -1143,7 +1147,7 @@ func setupAndInitializeLoggingAndProfiling(
if addr == "" {
addr = "any of your IP addresses"
}
log.Ops.Shoutf(context.Background(), severity.WARNING,
log.Ops.Shoutf(ctx, severity.WARNING,
"ALL SECURITY CONTROLS HAVE BEEN DISABLED!\n\n"+
"This mode is intended for non-production testing only.\n"+
"\n"+
Expand All @@ -1153,7 +1157,7 @@ func setupAndInitializeLoggingAndProfiling(
"- Intruders can log in without password and read or write any data in the cluster.\n"+
"- Intruders can consume all your server's resources and cause unavailability.",
addr)
log.Ops.Shoutf(context.Background(), severity.INFO,
log.Ops.Shoutf(ctx, severity.INFO,
"To start a secure server without mandating TLS for clients,\n"+
"consider --accept-sql-without-tls instead. For other options, see:\n\n"+
"- %s\n"+
Expand All @@ -1172,7 +1176,7 @@ func setupAndInitializeLoggingAndProfiling(
"to databases, the --locality flag must contain a \"region\" tier.\n" +
"For more information, see:\n\n" +
"- %s"
log.Shoutf(context.Background(), severity.WARNING, warningString,
log.Shoutf(ctx, severity.WARNING, warningString,
log.Safe(docs.URL("cockroach-start.html#locality")))
}
}
Expand Down
2 changes: 1 addition & 1 deletion pkg/util/log/channels.go
Original file line number Diff line number Diff line change
Expand Up @@ -78,7 +78,7 @@ func shoutfDepth(
// it here.
fmt.Fprintf(OrigStderr, "*\n* %s: %s\n*\n", sev.String(),
strings.Replace(
FormatWithContextTags(ctx, format, args...),
formatOnlyArgs(format, args...),
"\n", "\n* ", -1))
}
logfDepth(ctx, depth+1, sev, ch, format, args...)
Expand Down
6 changes: 6 additions & 0 deletions pkg/util/log/structured.go
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,12 @@ func FormatWithContextTags(ctx context.Context, format string, args ...interface
return buf.String()
}

func formatOnlyArgs(format string, args ...interface{}) string {
var buf strings.Builder
formatArgs(&buf, format, args...)
return buf.String()
}

func formatArgs(buf *strings.Builder, format string, args ...interface{}) {
if len(args) == 0 {
buf.WriteString(format)
Expand Down

0 comments on commit 9f86eb8

Please sign in to comment.