github.com/guilhermebr/docker@v1.4.2-0.20150428121140-67da055cebca/integration-cli/docker_cli_logs_test.go (about) 1 package main 2 3 import ( 4 "fmt" 5 "os/exec" 6 "regexp" 7 "strings" 8 "time" 9 10 "github.com/docker/docker/pkg/timeutils" 11 "github.com/go-check/check" 12 ) 13 14 // This used to work, it test a log of PageSize-1 (gh#4851) 15 func (s *DockerSuite) TestLogsContainerSmallerThanPage(c *check.C) { 16 testLen := 32767 17 runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("for i in $(seq 1 %d); do echo -n =; done; echo", testLen)) 18 out, _, _, err := runCommandWithStdoutStderr(runCmd) 19 if err != nil { 20 c.Fatalf("run failed with errors: %s, %v", out, err) 21 } 22 23 cleanedContainerID := strings.TrimSpace(out) 24 exec.Command(dockerBinary, "wait", cleanedContainerID).Run() 25 26 logsCmd := exec.Command(dockerBinary, "logs", cleanedContainerID) 27 out, _, _, err = runCommandWithStdoutStderr(logsCmd) 28 if err != nil { 29 c.Fatalf("failed to log container: %s, %v", out, err) 30 } 31 32 if len(out) != testLen+1 { 33 c.Fatalf("Expected log length of %d, received %d\n", testLen+1, len(out)) 34 } 35 36 deleteContainer(cleanedContainerID) 37 38 } 39 40 // Regression test: When going over the PageSize, it used to panic (gh#4851) 41 func (s *DockerSuite) TestLogsContainerBiggerThanPage(c *check.C) { 42 testLen := 32768 43 runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("for i in $(seq 1 %d); do echo -n =; done; echo", testLen)) 44 out, _, _, err := runCommandWithStdoutStderr(runCmd) 45 if err != nil { 46 c.Fatalf("run failed with errors: %s, %v", out, err) 47 } 48 49 cleanedContainerID := strings.TrimSpace(out) 50 exec.Command(dockerBinary, "wait", cleanedContainerID).Run() 51 52 logsCmd := exec.Command(dockerBinary, "logs", cleanedContainerID) 53 out, _, _, err = runCommandWithStdoutStderr(logsCmd) 54 if err != nil { 55 c.Fatalf("failed to log container: %s, %v", out, err) 56 } 57 58 if len(out) != testLen+1 { 59 c.Fatalf("Expected log length of %d, received %d\n", testLen+1, len(out)) 60 } 61 62 deleteContainer(cleanedContainerID) 63 64 } 65 66 // Regression test: When going much over the PageSize, it used to block (gh#4851) 67 func (s *DockerSuite) TestLogsContainerMuchBiggerThanPage(c *check.C) { 68 testLen := 33000 69 runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("for i in $(seq 1 %d); do echo -n =; done; echo", testLen)) 70 out, _, _, err := runCommandWithStdoutStderr(runCmd) 71 if err != nil { 72 c.Fatalf("run failed with errors: %s, %v", out, err) 73 } 74 75 cleanedContainerID := strings.TrimSpace(out) 76 exec.Command(dockerBinary, "wait", cleanedContainerID).Run() 77 78 logsCmd := exec.Command(dockerBinary, "logs", cleanedContainerID) 79 out, _, _, err = runCommandWithStdoutStderr(logsCmd) 80 if err != nil { 81 c.Fatalf("failed to log container: %s, %v", out, err) 82 } 83 84 if len(out) != testLen+1 { 85 c.Fatalf("Expected log length of %d, received %d\n", testLen+1, len(out)) 86 } 87 88 deleteContainer(cleanedContainerID) 89 90 } 91 92 func (s *DockerSuite) TestLogsTimestamps(c *check.C) { 93 testLen := 100 94 runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("for i in $(seq 1 %d); do echo =; done;", testLen)) 95 96 out, _, _, err := runCommandWithStdoutStderr(runCmd) 97 if err != nil { 98 c.Fatalf("run failed with errors: %s, %v", out, err) 99 } 100 101 cleanedContainerID := strings.TrimSpace(out) 102 exec.Command(dockerBinary, "wait", cleanedContainerID).Run() 103 104 logsCmd := exec.Command(dockerBinary, "logs", "-t", cleanedContainerID) 105 out, _, _, err = runCommandWithStdoutStderr(logsCmd) 106 if err != nil { 107 c.Fatalf("failed to log container: %s, %v", out, err) 108 } 109 110 lines := strings.Split(out, "\n") 111 112 if len(lines) != testLen+1 { 113 c.Fatalf("Expected log %d lines, received %d\n", testLen+1, len(lines)) 114 } 115 116 ts := regexp.MustCompile(`^.* `) 117 118 for _, l := range lines { 119 if l != "" { 120 _, err := time.Parse(timeutils.RFC3339NanoFixed+" ", ts.FindString(l)) 121 if err != nil { 122 c.Fatalf("Failed to parse timestamp from %v: %v", l, err) 123 } 124 if l[29] != 'Z' { // ensure we have padded 0's 125 c.Fatalf("Timestamp isn't padded properly: %s", l) 126 } 127 } 128 } 129 130 deleteContainer(cleanedContainerID) 131 132 } 133 134 func (s *DockerSuite) TestLogsSeparateStderr(c *check.C) { 135 msg := "stderr_log" 136 runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("echo %s 1>&2", msg)) 137 138 out, _, _, err := runCommandWithStdoutStderr(runCmd) 139 if err != nil { 140 c.Fatalf("run failed with errors: %s, %v", out, err) 141 } 142 143 cleanedContainerID := strings.TrimSpace(out) 144 exec.Command(dockerBinary, "wait", cleanedContainerID).Run() 145 146 logsCmd := exec.Command(dockerBinary, "logs", cleanedContainerID) 147 stdout, stderr, _, err := runCommandWithStdoutStderr(logsCmd) 148 if err != nil { 149 c.Fatalf("failed to log container: %s, %v", out, err) 150 } 151 152 if stdout != "" { 153 c.Fatalf("Expected empty stdout stream, got %v", stdout) 154 } 155 156 stderr = strings.TrimSpace(stderr) 157 if stderr != msg { 158 c.Fatalf("Expected %v in stderr stream, got %v", msg, stderr) 159 } 160 161 deleteContainer(cleanedContainerID) 162 163 } 164 165 func (s *DockerSuite) TestLogsStderrInStdout(c *check.C) { 166 msg := "stderr_log" 167 runCmd := exec.Command(dockerBinary, "run", "-d", "-t", "busybox", "sh", "-c", fmt.Sprintf("echo %s 1>&2", msg)) 168 169 out, _, _, err := runCommandWithStdoutStderr(runCmd) 170 if err != nil { 171 c.Fatalf("run failed with errors: %s, %v", out, err) 172 } 173 174 cleanedContainerID := strings.TrimSpace(out) 175 exec.Command(dockerBinary, "wait", cleanedContainerID).Run() 176 177 logsCmd := exec.Command(dockerBinary, "logs", cleanedContainerID) 178 stdout, stderr, _, err := runCommandWithStdoutStderr(logsCmd) 179 if err != nil { 180 c.Fatalf("failed to log container: %s, %v", out, err) 181 } 182 183 if stderr != "" { 184 c.Fatalf("Expected empty stderr stream, got %v", stdout) 185 } 186 187 stdout = strings.TrimSpace(stdout) 188 if stdout != msg { 189 c.Fatalf("Expected %v in stdout stream, got %v", msg, stdout) 190 } 191 192 deleteContainer(cleanedContainerID) 193 194 } 195 196 func (s *DockerSuite) TestLogsTail(c *check.C) { 197 testLen := 100 198 runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("for i in $(seq 1 %d); do echo =; done;", testLen)) 199 200 out, _, _, err := runCommandWithStdoutStderr(runCmd) 201 if err != nil { 202 c.Fatalf("run failed with errors: %s, %v", out, err) 203 } 204 205 cleanedContainerID := strings.TrimSpace(out) 206 exec.Command(dockerBinary, "wait", cleanedContainerID).Run() 207 208 logsCmd := exec.Command(dockerBinary, "logs", "--tail", "5", cleanedContainerID) 209 out, _, _, err = runCommandWithStdoutStderr(logsCmd) 210 if err != nil { 211 c.Fatalf("failed to log container: %s, %v", out, err) 212 } 213 214 lines := strings.Split(out, "\n") 215 216 if len(lines) != 6 { 217 c.Fatalf("Expected log %d lines, received %d\n", 6, len(lines)) 218 } 219 220 logsCmd = exec.Command(dockerBinary, "logs", "--tail", "all", cleanedContainerID) 221 out, _, _, err = runCommandWithStdoutStderr(logsCmd) 222 if err != nil { 223 c.Fatalf("failed to log container: %s, %v", out, err) 224 } 225 226 lines = strings.Split(out, "\n") 227 228 if len(lines) != testLen+1 { 229 c.Fatalf("Expected log %d lines, received %d\n", testLen+1, len(lines)) 230 } 231 232 logsCmd = exec.Command(dockerBinary, "logs", "--tail", "random", cleanedContainerID) 233 out, _, _, err = runCommandWithStdoutStderr(logsCmd) 234 if err != nil { 235 c.Fatalf("failed to log container: %s, %v", out, err) 236 } 237 238 lines = strings.Split(out, "\n") 239 240 if len(lines) != testLen+1 { 241 c.Fatalf("Expected log %d lines, received %d\n", testLen+1, len(lines)) 242 } 243 244 deleteContainer(cleanedContainerID) 245 } 246 247 func (s *DockerSuite) TestLogsFollowStopped(c *check.C) { 248 runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "echo", "hello") 249 250 out, _, _, err := runCommandWithStdoutStderr(runCmd) 251 if err != nil { 252 c.Fatalf("run failed with errors: %s, %v", out, err) 253 } 254 255 cleanedContainerID := strings.TrimSpace(out) 256 exec.Command(dockerBinary, "wait", cleanedContainerID).Run() 257 258 logsCmd := exec.Command(dockerBinary, "logs", "-f", cleanedContainerID) 259 if err := logsCmd.Start(); err != nil { 260 c.Fatal(err) 261 } 262 263 ch := make(chan struct{}) 264 go func() { 265 if err := logsCmd.Wait(); err != nil { 266 c.Fatal(err) 267 } 268 close(ch) 269 }() 270 271 select { 272 case <-ch: 273 case <-time.After(1 * time.Second): 274 c.Fatal("Following logs is hanged") 275 } 276 277 deleteContainer(cleanedContainerID) 278 } 279 280 // Regression test for #8832 281 func (s *DockerSuite) TestLogsFollowSlowStdoutConsumer(c *check.C) { 282 runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "/bin/sh", "-c", `usleep 200000;yes X | head -c 200000`) 283 284 out, _, _, err := runCommandWithStdoutStderr(runCmd) 285 if err != nil { 286 c.Fatalf("run failed with errors: %s, %v", out, err) 287 } 288 289 cleanedContainerID := strings.TrimSpace(out) 290 291 stopSlowRead := make(chan bool) 292 293 go func() { 294 exec.Command(dockerBinary, "wait", cleanedContainerID).Run() 295 stopSlowRead <- true 296 }() 297 298 logCmd := exec.Command(dockerBinary, "logs", "-f", cleanedContainerID) 299 300 stdout, err := logCmd.StdoutPipe() 301 if err != nil { 302 c.Fatal(err) 303 } 304 305 if err := logCmd.Start(); err != nil { 306 c.Fatal(err) 307 } 308 309 // First read slowly 310 bytes1, err := consumeWithSpeed(stdout, 10, 50*time.Millisecond, stopSlowRead) 311 if err != nil { 312 c.Fatal(err) 313 } 314 315 // After the container has finished we can continue reading fast 316 bytes2, err := consumeWithSpeed(stdout, 32*1024, 0, nil) 317 if err != nil { 318 c.Fatal(err) 319 } 320 321 actual := bytes1 + bytes2 322 expected := 200000 323 if actual != expected { 324 c.Fatalf("Invalid bytes read: %d, expected %d", actual, expected) 325 } 326 327 }