Browse code

Fix goroutine leak on logs -f with no output

Also noticed potential hang when only stdout or stderr are used with
follow=1

Signed-off-by: Brian Goff <cpuguy83@gmail.com>

Brian Goff authored on 2015/06/05 04:15:33
Showing 3 changed files
... ...
@@ -597,6 +597,11 @@ func (s *Server) getContainersLogs(version version.Version, w http.ResponseWrite
597 597
 		since = time.Unix(s, 0)
598 598
 	}
599 599
 
600
+	var closeNotifier <-chan bool
601
+	if notifier, ok := w.(http.CloseNotifier); ok {
602
+		closeNotifier = notifier.CloseNotify()
603
+	}
604
+
600 605
 	logsConfig := &daemon.ContainerLogsConfig{
601 606
 		Follow:     boolValue(r, "follow"),
602 607
 		Timestamps: boolValue(r, "timestamps"),
... ...
@@ -605,6 +610,7 @@ func (s *Server) getContainersLogs(version version.Version, w http.ResponseWrite
605 605
 		UseStdout:  stdout,
606 606
 		UseStderr:  stderr,
607 607
 		OutStream:  ioutils.NewWriteFlusher(w),
608
+		Stop:       closeNotifier,
608 609
 	}
609 610
 
610 611
 	if err := s.daemon.ContainerLogs(vars["name"], logsConfig); err != nil {
... ...
@@ -25,6 +25,7 @@ type ContainerLogsConfig struct {
25 25
 	Since                time.Time
26 26
 	UseStdout, UseStderr bool
27 27
 	OutStream            io.Writer
28
+	Stop                 <-chan bool
28 29
 }
29 30
 
30 31
 func (daemon *Daemon) ContainerLogs(name string, config *ContainerLogsConfig) error {
... ...
@@ -119,7 +120,8 @@ func (daemon *Daemon) ContainerLogs(name string, config *ContainerLogsConfig) er
119 119
 	}
120 120
 
121 121
 	if config.Follow && container.IsRunning() {
122
-		chErr := make(chan error)
122
+		chErrStderr := make(chan error)
123
+		chErrStdout := make(chan error)
123 124
 		var stdoutPipe, stderrPipe io.ReadCloser
124 125
 
125 126
 		// write an empty chunk of data (this is to ensure that the
... ...
@@ -131,7 +133,7 @@ func (daemon *Daemon) ContainerLogs(name string, config *ContainerLogsConfig) er
131 131
 			stdoutPipe = container.StdoutLogPipe()
132 132
 			go func() {
133 133
 				logrus.Debug("logs: stdout stream begin")
134
-				chErr <- jsonlog.WriteLog(stdoutPipe, outStream, format, config.Since)
134
+				chErrStdout <- jsonlog.WriteLog(stdoutPipe, outStream, format, config.Since)
135 135
 				logrus.Debug("logs: stdout stream end")
136 136
 			}()
137 137
 		}
... ...
@@ -139,19 +141,33 @@ func (daemon *Daemon) ContainerLogs(name string, config *ContainerLogsConfig) er
139 139
 			stderrPipe = container.StderrLogPipe()
140 140
 			go func() {
141 141
 				logrus.Debug("logs: stderr stream begin")
142
-				chErr <- jsonlog.WriteLog(stderrPipe, errStream, format, config.Since)
142
+				chErrStderr <- jsonlog.WriteLog(stderrPipe, errStream, format, config.Since)
143 143
 				logrus.Debug("logs: stderr stream end")
144 144
 			}()
145 145
 		}
146 146
 
147
-		err = <-chErr
148
-		if stdoutPipe != nil {
149
-			stdoutPipe.Close()
150
-		}
151
-		if stderrPipe != nil {
152
-			stderrPipe.Close()
147
+		select {
148
+		case err = <-chErrStderr:
149
+			if stdoutPipe != nil {
150
+				stdoutPipe.Close()
151
+				<-chErrStdout
152
+			}
153
+		case err = <-chErrStdout:
154
+			if stderrPipe != nil {
155
+				stderrPipe.Close()
156
+				<-chErrStderr
157
+			}
158
+		case <-config.Stop:
159
+			if stdoutPipe != nil {
160
+				stdoutPipe.Close()
161
+				<-chErrStdout
162
+			}
163
+			if stderrPipe != nil {
164
+				stderrPipe.Close()
165
+				<-chErrStderr
166
+			}
167
+			return nil
153 168
 		}
154
-		<-chErr // wait for 2nd goroutine to exit, otherwise bad things will happen
155 169
 
156 170
 		if err != nil && err != io.EOF && err != io.ErrClosedPipe {
157 171
 			if e, ok := err.(*net.OpError); ok && e.Err != syscall.EPIPE {
... ...
@@ -425,3 +425,44 @@ func (s *DockerSuite) TestLogsFollowGoroutinesWithStdout(c *check.C) {
425 425
 		}
426 426
 	}
427 427
 }
428
+
429
+func (s *DockerSuite) TestLogsFollowGoroutinesNoOutput(c *check.C) {
430
+	out, _ := dockerCmd(c, "run", "-d", "busybox", "/bin/sh", "-c", "while true; do sleep 2; done")
431
+	id := strings.TrimSpace(out)
432
+	c.Assert(waitRun(id), check.IsNil)
433
+
434
+	type info struct {
435
+		NGoroutines int
436
+	}
437
+	getNGoroutines := func() int {
438
+		var i info
439
+		status, b, err := sockRequest("GET", "/info", nil)
440
+		c.Assert(err, check.IsNil)
441
+		c.Assert(status, check.Equals, 200)
442
+		c.Assert(json.Unmarshal(b, &i), check.IsNil)
443
+		return i.NGoroutines
444
+	}
445
+
446
+	nroutines := getNGoroutines()
447
+
448
+	cmd := exec.Command(dockerBinary, "logs", "-f", id)
449
+	c.Assert(cmd.Start(), check.IsNil)
450
+	time.Sleep(200 * time.Millisecond)
451
+	c.Assert(cmd.Process.Kill(), check.IsNil)
452
+
453
+	// NGoroutines is not updated right away, so we need to wait before failing
454
+	t := time.After(30 * time.Second)
455
+	for {
456
+		select {
457
+		case <-t:
458
+			if n := getNGoroutines(); n > nroutines {
459
+				c.Fatalf("leaked goroutines: expected less than or equal to %d, got: %d", nroutines, n)
460
+			}
461
+		default:
462
+			if n := getNGoroutines(); n <= nroutines {
463
+				return
464
+			}
465
+			time.Sleep(200 * time.Millisecond)
466
+		}
467
+	}
468
+}