From 4f058e32e03415a0076ae1e25d8f331a5a7b2c20 Mon Sep 17 00:00:00 2001 From: Prateek Dwivedi Date: Mon, 26 Feb 2024 08:44:40 -0800 Subject: [PATCH 01/10] Added error handling for context.Canceled in log reading code --- docker.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/docker.go b/docker.go index 33a73cae73..52bab0b518 100644 --- a/docker.go +++ b/docker.go @@ -756,7 +756,7 @@ func (c *DockerContainer) startLogProduction(ctx context.Context, opts ...LogPro if err != nil { // TODO: add-logger: use logger to log out this error _, _ = fmt.Fprintf(os.Stderr, "error occurred reading log with known length %s", err.Error()) - if errors.Is(err, context.DeadlineExceeded) { + if errors.Is(err, context.DeadlineExceeded) || errors.Is(err, context.Canceled) { // Probably safe to continue here continue } From e1e9ecaac69cc9efcf6c320bf8a461930c2bc0f8 Mon Sep 17 00:00:00 2001 From: Prateek Dwivedi Date: Wed, 28 Feb 2024 21:43:50 -0800 Subject: [PATCH 02/10] Added error handling for context.Canceled in log reading code --- docker.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/docker.go b/docker.go index 52bab0b518..cb799dc05a 100644 --- a/docker.go +++ b/docker.go @@ -728,7 +728,7 @@ func (c *DockerContainer) startLogProduction(ctx context.Context, opts ...LogPro since = fmt.Sprintf("%d.%09d", now.Unix(), int64(now.Nanosecond())) goto BEGIN } - if errors.Is(err, context.DeadlineExceeded) { + if errors.Is(err, context.DeadlineExceeded) || errors.Is(err, context.Canceled) { // Probably safe to continue here continue } From be7c25e1b56467234983d1e390502f3222e153e4 Mon Sep 17 00:00:00 2001 From: Prateek Dwivedi Date: Wed, 28 Feb 2024 21:46:58 -0800 Subject: [PATCH 03/10] Added test case for context canceled error handling --- logconsumer_test.go | 105 ++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 105 insertions(+) diff --git a/logconsumer_test.go b/logconsumer_test.go index 3416c73f79..007949d777 100644 --- a/logconsumer_test.go +++ b/logconsumer_test.go @@ -508,3 +508,108 @@ func Test_StartLogProductionStillStartsWithTooHighTimeout(t *testing.T) { terminateContainerOnEnd(t, ctx, c) } + +func Test_MultiContainerLogConsumer_CancelledContext(t *testing.T) { + // Redirect stderr to a buffer + oldStderr := os.Stderr + r, w, _ := os.Pipe() + os.Stderr = w + + // Context with cancellation functionality for handling interrupt (SIGINT) and + // termination (SIGTERM) signals. + ctx, cancel := signal.NotifyContext(context.Background(), os.Interrupt, syscall.SIGTERM) + + first := TestLogConsumer{ + Msgs: []string{}, + Done: make(chan bool), + Accepted: devNullAcceptorChan(), + } + + containerReq1 := ContainerRequest{ + FromDockerfile: FromDockerfile{ + Context: "./testdata/", + Dockerfile: "echoserver.Dockerfile", + }, + ExposedPorts: []string{"8080/tcp"}, + WaitingFor: wait.ForLog("ready"), + LogConsumerCfg: &LogConsumerConfig{ + Consumers: []LogConsumer{&first}, + }, + } + + genericReq1 := GenericContainerRequest{ + ContainerRequest: containerReq1, + Started: true, + } + + c, err := GenericContainer(ctx, genericReq1) + require.NoError(t, err) + + ep1, err := c.Endpoint(ctx, "http") + require.NoError(t, err) + + _, err = http.Get(ep1 + "/stdout?echo=hello1") + require.NoError(t, err) + + _, err = http.Get(ep1 + "/stdout?echo=there1") + require.NoError(t, err) + + second := TestLogConsumer{ + Msgs: []string{}, + Done: make(chan bool), + Accepted: devNullAcceptorChan(), + } + + containerReq2 := ContainerRequest{ + FromDockerfile: FromDockerfile{ + Context: "./testdata/", + Dockerfile: "echoserver.Dockerfile", + }, + ExposedPorts: []string{"8080/tcp"}, + WaitingFor: wait.ForLog("ready"), + LogConsumerCfg: &LogConsumerConfig{ + Consumers: []LogConsumer{&second}, + }, + } + + genericReq2 := GenericContainerRequest{ + ContainerRequest: containerReq2, + Started: true, + } + + c2, err := GenericContainer(ctx, genericReq2) + require.NoError(t, err) + + ep2, err := c2.Endpoint(ctx, "http") + require.NoError(t, err) + + _, err = http.Get(ep2 + "/stdout?echo=hello2") + require.NoError(t, err) + + _, err = http.Get(ep2 + "/stdout?echo=there2") + require.NoError(t, err) + + // Deliberately calling context cancel + cancel() + + // Check the log messages + assert.Equal(t, []string{"ready\n", "echo hello1\n", "echo there1\n"}, first.Msgs) + assert.Equal(t, []string{"ready\n", "echo hello2\n", "echo there2\n"}, second.Msgs) + + // Restore stderr + w.Close() + os.Stderr = oldStderr + + // Read the stderr output from the buffer + var buf bytes.Buffer + _, _ = buf.ReadFrom(r) + + // Check the stderr message + actual := buf.String() + + // The context cancel shouldn't cause the system to throw a + // logStoppedForOutOfSyncMessage, as it hangs the system with + // the multiple containers. + assert.False(t, strings.Contains(actual, logStoppedForOutOfSyncMessage)) +} + From 658bc2af348d9b92510e061dc57be28968a92562 Mon Sep 17 00:00:00 2001 From: Prateek Dwivedi Date: Wed, 28 Feb 2024 23:10:29 -0800 Subject: [PATCH 04/10] Added necessary import statement for log consumer test --- logconsumer_test.go | 3 +++ 1 file changed, 3 insertions(+) diff --git a/logconsumer_test.go b/logconsumer_test.go index 007949d777..cd16e72b12 100644 --- a/logconsumer_test.go +++ b/logconsumer_test.go @@ -1,13 +1,16 @@ package testcontainers import ( + "bytes" "context" "errors" "fmt" "io" "net/http" "os" + "os/signal" "strings" + "syscall" "testing" "time" From ded08d37a4fbca66f1601b7375984c1a68509712 Mon Sep 17 00:00:00 2001 From: Prateek Dwivedi Date: Thu, 29 Feb 2024 13:32:57 -0800 Subject: [PATCH 05/10] `make lint` changes --- logconsumer_test.go | 1 - 1 file changed, 1 deletion(-) diff --git a/logconsumer_test.go b/logconsumer_test.go index cd16e72b12..70f064a2ab 100644 --- a/logconsumer_test.go +++ b/logconsumer_test.go @@ -615,4 +615,3 @@ func Test_MultiContainerLogConsumer_CancelledContext(t *testing.T) { // the multiple containers. assert.False(t, strings.Contains(actual, logStoppedForOutOfSyncMessage)) } - From 1ca31e104a3c15834747e1f0f4ee2a71d47065fb Mon Sep 17 00:00:00 2001 From: Prateek Dwivedi Date: Fri, 1 Mar 2024 00:39:50 -0800 Subject: [PATCH 06/10] Handled the termination of the containers --- logconsumer_test.go | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/logconsumer_test.go b/logconsumer_test.go index 70f064a2ab..27533caa42 100644 --- a/logconsumer_test.go +++ b/logconsumer_test.go @@ -592,6 +592,17 @@ func Test_MultiContainerLogConsumer_CancelledContext(t *testing.T) { _, err = http.Get(ep2 + "/stdout?echo=there2") require.NoError(t, err) + + // Handling the termination of the containers + defer func() { + shutdownCtx, shutdownCancel := context.WithTimeout( + context.Background(), 30*time.Second, + ) + defer shutdownCancel() + _ = c.Terminate(shutdownCtx) + _ = c2.Terminate(shutdownCtx) + }() + // Deliberately calling context cancel cancel() From f6d20892a140744395d256b0b4523081534a53dd Mon Sep 17 00:00:00 2001 From: Prateek Dwivedi Date: Fri, 1 Mar 2024 00:44:19 -0800 Subject: [PATCH 07/10] `make lint` changes --- logconsumer_test.go | 1 - 1 file changed, 1 deletion(-) diff --git a/logconsumer_test.go b/logconsumer_test.go index 27533caa42..2d86eee2b0 100644 --- a/logconsumer_test.go +++ b/logconsumer_test.go @@ -592,7 +592,6 @@ func Test_MultiContainerLogConsumer_CancelledContext(t *testing.T) { _, err = http.Get(ep2 + "/stdout?echo=there2") require.NoError(t, err) - // Handling the termination of the containers defer func() { shutdownCtx, shutdownCancel := context.WithTimeout( From 040c9e4cfd3faad176819116020bd4a853c4ab1b Mon Sep 17 00:00:00 2001 From: Prateek Dwivedi Date: Tue, 5 Mar 2024 09:08:16 -0800 Subject: [PATCH 08/10] Cancelled log consumer test: Increased timeout --- logconsumer_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/logconsumer_test.go b/logconsumer_test.go index 2d86eee2b0..31734727fb 100644 --- a/logconsumer_test.go +++ b/logconsumer_test.go @@ -595,7 +595,7 @@ func Test_MultiContainerLogConsumer_CancelledContext(t *testing.T) { // Handling the termination of the containers defer func() { shutdownCtx, shutdownCancel := context.WithTimeout( - context.Background(), 30*time.Second, + context.Background(), 60*time.Second, ) defer shutdownCancel() _ = c.Terminate(shutdownCtx) From fa2820d4e5153d667958f1f6c390d412e77ffd5b Mon Sep 17 00:00:00 2001 From: Prateek Dwivedi Date: Wed, 6 Mar 2024 23:29:34 -0800 Subject: [PATCH 09/10] Changes based on review comments --- logconsumer_test.go | 7 ++----- 1 file changed, 2 insertions(+), 5 deletions(-) diff --git a/logconsumer_test.go b/logconsumer_test.go index 31734727fb..fb7e82aa06 100644 --- a/logconsumer_test.go +++ b/logconsumer_test.go @@ -8,9 +8,7 @@ import ( "io" "net/http" "os" - "os/signal" "strings" - "syscall" "testing" "time" @@ -518,9 +516,8 @@ func Test_MultiContainerLogConsumer_CancelledContext(t *testing.T) { r, w, _ := os.Pipe() os.Stderr = w - // Context with cancellation functionality for handling interrupt (SIGINT) and - // termination (SIGTERM) signals. - ctx, cancel := signal.NotifyContext(context.Background(), os.Interrupt, syscall.SIGTERM) + // Context with cancellation functionality for simulating user interruption + ctx, cancel := context.WithCancel(context.Background()) first := TestLogConsumer{ Msgs: []string{}, From beb3de696c4a478482b32559f62667d47ae106b6 Mon Sep 17 00:00:00 2001 From: Prateek Dwivedi Date: Thu, 7 Mar 2024 20:21:43 -0800 Subject: [PATCH 10/10] Updated check for log messages in the Cancelled Context test --- logconsumer_test.go | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/logconsumer_test.go b/logconsumer_test.go index fb7e82aa06..9c9b25fa09 100644 --- a/logconsumer_test.go +++ b/logconsumer_test.go @@ -602,9 +602,10 @@ func Test_MultiContainerLogConsumer_CancelledContext(t *testing.T) { // Deliberately calling context cancel cancel() - // Check the log messages - assert.Equal(t, []string{"ready\n", "echo hello1\n", "echo there1\n"}, first.Msgs) - assert.Equal(t, []string{"ready\n", "echo hello2\n", "echo there2\n"}, second.Msgs) + // We check log size due to context cancellation causing + // varying message counts, leading to test failure. + assert.GreaterOrEqual(t, len(first.Msgs), 2) + assert.GreaterOrEqual(t, len(second.Msgs), 2) // Restore stderr w.Close()