Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Added WaitGroups to prevent stderr/stdout from being empty in error logs #10694

Merged
merged 2 commits into from
Mar 3, 2021
Merged

Added WaitGroups to prevent stderr/stdout from being empty in error logs #10694

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
35ca6d7
added WaitGroups to make sure logs have finished writing before conti…
spowelljr Mar 2, 2021
b40a41d
added ssh.Close back
spowelljr Mar 2, 2021
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 0 additions & 1 deletion go.mod
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -94,7 +94,6 @@ require (
gopkg.in/mgo.v2 v2.0.0-20190816093944-a6b53ec6cb22 // indirect
gopkg.in/yaml.v2 v2.4.0
gotest.tools/v3 v3.0.2 // indirect
honnef.co/go/tools v0.0.1-2020.1.4 // indirect
k8s.io/api v0.18.8
k8s.io/apimachinery v0.18.8
k8s.io/client-go v0.18.8
Expand Down
6 changes: 3 additions & 3 deletions go.sum
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -753,8 +753,8 @@ github.com/otiai10/curr v0.0.0-20150429015615-9b4961190c95/go.mod h1:9qAhocn7zKJ
github.com/otiai10/mint v1.3.0 h1:Ady6MKVezQwHBkGzLFbrsywyp09Ah7rkmfjV3Bcr5uc=
github.com/otiai10/mint v1.3.0/go.mod h1:F5AjcsTsWUqX+Na9fpHb52P8pcRX2CI6A3ctIT91xUo=
github.com/pascaldekloe/goe v0.0.0-20180627143212-57f6aae5913c/go.mod h1:lzWF7FIEvWOWxwDKqyGYQf6ZUaNfKdP144TG7ZOy1lc=
github.com/pborman/uuid v1.2.0 h1:J7Q5mO4ysT1dv8hyrUGHb9+ooztCXu1D8MY8DZYsu3g=
github.com/pborman/uuid v1.2.0/go.mod h1:X/NO0urCmaxf9VXbdlT7C2Yzkj2IKimNn4k+gtPdI/k=
github.com/pborman/uuid v1.2.1 h1:+ZZIw58t/ozdjRaXh/3awHfmWRbzYxJoAdNJxe/3pvw=
github.com/pborman/uuid v1.2.1/go.mod h1:X/NO0urCmaxf9VXbdlT7C2Yzkj2IKimNn4k+gtPdI/k=
github.com/pelletier/go-toml v1.1.0/go.mod h1:5z9KED0ma1S8pY6P1sdut58dfprrGBbd/94hg7ilaic=
github.com/pelletier/go-toml v1.2.0 h1:T5zMGML61Wp+FlcbWjRDT7yAxhJNAiPPLOFECq181zc=
Expand Down Expand Up @@ -855,8 +855,8 @@ github.com/spf13/cobra v0.0.2-0.20171109065643-2da4a54c5cee/go.mod h1:1l0Ry5zgKv
github.com/spf13/cobra v0.0.2/go.mod h1:1l0Ry5zgKvJasoi3XT1TypsSe7PqH0Sj9dhYf7v3XqQ=
github.com/spf13/cobra v0.0.3/go.mod h1:1l0Ry5zgKvJasoi3XT1TypsSe7PqH0Sj9dhYf7v3XqQ=
github.com/spf13/cobra v0.0.5/go.mod h1:3K3wKZymM7VvHMDS9+Akkh4K60UwM26emMESw8tLCHU=
github.com/spf13/cobra v1.0.0 h1:6m/oheQuQ13N9ks4hubMG6BnvwOeaJrqSPLahSnczz8=
github.com/spf13/cobra v1.0.0/go.mod h1:/6GTrnGXV9HjY+aR4k0oJ5tcvakLuG6EuKReYlHNrgE=
github.com/spf13/cobra v1.1.3 h1:xghbfqPkxzxP3C/f3n5DdpAbdKLj4ZE4BWQI362l53M=
github.com/spf13/cobra v1.1.3/go.mod h1:pGADOWyqRD/YMrPZigI/zbliZ2wVD/23d+is3pSWzOo=
github.com/spf13/jwalterweatherman v0.0.0-20180109140146-7c0cea34c8ec/go.mod h1:cQK4TGJAtQXfYWX+Ddv3mKDzgVb68N+wFjFa4jdeBTo=
github.com/spf13/jwalterweatherman v1.0.0/go.mod h1:cQK4TGJAtQXfYWX+Ddv3mKDzgVb68N+wFjFa4jdeBTo=
Expand Down Expand Up @@ -1402,8 +1402,8 @@ gopkg.in/yaml.v2 v2.2.2/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=
gopkg.in/yaml.v2 v2.2.4/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=
gopkg.in/yaml.v2 v2.2.5/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=
gopkg.in/yaml.v2 v2.2.8/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=
gopkg.in/yaml.v2 v2.3.0 h1:clyUAQHOM3G0M3f5vQj7LuJrETvjVot3Z5el9nffUtU=
gopkg.in/yaml.v2 v2.3.0/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=
gopkg.in/yaml.v2 v2.4.0 h1:D8xgwECY7CYvx+Y2n4sBz93Jn9JRvxdiyyo8CTfuKaY=
gopkg.in/yaml.v2 v2.4.0/go.mod h1:RDklbk79AGWmwhnvt/jBztapEOGDOx6ZbXqjP6csGnQ=
gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c h1:dUUwHk2QECo/6vqA44rthZ8ie2QXMNeKRTHCNY2nXvo=
gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
Expand Down
10 changes: 7 additions & 3 deletions pkg/minikube/bootstrapper/kubeadm/kubeadm.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -239,11 +239,13 @@ func (k *Bootstrapper) init(cfg config.ClusterConfig) error {
bsutil.InvokeKubeadm(cfg.KubernetesConfig.KubernetesVersion), conf, extraFlags, strings.Join(ignore, ",")))
c.Stdout = kw
c.Stderr = kw
var wg sync.WaitGroup
wg.Add(1)
sc, err := k.c.StartCmd(c)
if err != nil {
return errors.Wrap(err, "start")
}
go outputKubeadmInitSteps(kr)
go outputKubeadmInitSteps(kr, &wg)
if _, err := k.c.WaitCmd(sc); err != nil {
if ctx.Err() == context.DeadlineExceeded {
return ErrInitTimedout
Expand All @@ -254,11 +256,12 @@ func (k *Bootstrapper) init(cfg config.ClusterConfig) error {
}
return errors.Wrap(err, "wait")
}
kw.Close()
Copy link
Member

Choose a reason for hiding this comment

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

I think this close should be after Wait

Copy link
Member Author

Choose a reason for hiding this comment

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

When we get to this line, all the logs are in the pipeline but may not have finished being processed, so we close the pipeline. Closing the pipeline doesn't kill it, instead it writes EOF to the pipe and then prevents new writes. Once the pipeline is emptied it hits the EOF and calls wg.Done() (line 322) and then the wg.Wait() on the next line is unblocked.

tl;dr: If they were in the other order it would block forever because the pipeline processing would be waiting for a EOF which is only added on kw.Close().

wg.Wait()
if err := k.applyCNI(cfg); err != nil {
return errors.Wrap(err, "apply cni")
}

var wg sync.WaitGroup
wg.Add(3)

go func() {
Expand Down Expand Up @@ -288,7 +291,7 @@ func (k *Bootstrapper) init(cfg config.ClusterConfig) error {
}

// outputKubeadmInitSteps streams the pipe and outputs the current step
func outputKubeadmInitSteps(logs io.Reader) {
func outputKubeadmInitSteps(logs io.Reader, wg *sync.WaitGroup) {
type step struct {
logTag string
registerStep register.RegStep
Expand Down Expand Up @@ -316,6 +319,7 @@ func outputKubeadmInitSteps(logs io.Reader) {
out.Step(style.SubStep, nextStep.stepMessage)
nextStepIndex++
}
wg.Done()
}

// applyCNI applies CNI to a cluster. Needs to be done every time a VM is powered up.
Expand Down
1 change: 1 addition & 0 deletions pkg/minikube/command/command_runner.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -55,6 +55,7 @@ type RunResult struct {
type StartedCmd struct {
cmd *exec.Cmd
rr *RunResult
wg *sync.WaitGroup
}

// Runner represents an interface to run commands.
Expand Down
12 changes: 9 additions & 3 deletions pkg/minikube/command/ssh_runner.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -196,7 +196,7 @@ func (s *SSHRunner) RunCmd(cmd *exec.Cmd) (*RunResult, error) {
}

// teeSSHStart starts a non-blocking SSH command, streaming stdout, stderr to logs
func teeSSHStart(s *ssh.Session, cmd string, outB io.Writer, errB io.Writer) error {
func teeSSHStart(s *ssh.Session, cmd string, outB io.Writer, errB io.Writer, wg *sync.WaitGroup) error {
outPipe, err := s.StdoutPipe()
if err != nil {
return errors.Wrap(err, "stdout")
Expand All @@ -211,11 +211,13 @@ func teeSSHStart(s *ssh.Session, cmd string, outB io.Writer, errB io.Writer) err
if err := teePrefix(ErrPrefix, errPipe, errB, klog.V(8).Infof); err != nil {
klog.Errorf("tee stderr: %v", err)
}
wg.Done()
}()
go func() {
if err := teePrefix(OutPrefix, outPipe, outB, klog.V(8).Infof); err != nil {
klog.Errorf("tee stdout: %v", err)
}
wg.Done()
}()

return s.Start(cmd)
Expand All @@ -231,8 +233,10 @@ func (s *SSHRunner) StartCmd(cmd *exec.Cmd) (*StartedCmd, error) {
return nil, fmt.Errorf("another SSH command has been started and is currently running")
}

var wg sync.WaitGroup
wg.Add(2)
rr := &RunResult{Args: cmd.Args}
sc := &StartedCmd{cmd: cmd, rr: rr}
sc := &StartedCmd{cmd: cmd, rr: rr, wg: &wg}
klog.Infof("Start: %v", rr.Command())

var outb, errb io.Writer
Expand All @@ -258,7 +262,7 @@ func (s *SSHRunner) StartCmd(cmd *exec.Cmd) (*StartedCmd, error) {

s.s = sess

err = teeSSHStart(s.s, shellquote.Join(cmd.Args...), outb, errb)
err = teeSSHStart(s.s, shellquote.Join(cmd.Args...), outb, errb, &wg)

return sc, err
}
Expand All @@ -276,6 +280,8 @@ func (s *SSHRunner) WaitCmd(sc *StartedCmd) (*RunResult, error) {
rr.ExitCode = exitError.ExitCode()
}

sc.wg.Wait()

if err := s.s.Close(); err != io.EOF {
klog.Errorf("session close: %v", err)
}
Expand Down