diff --git a/executor/linux/build_test.go b/executor/linux/build_test.go index 28f168a6..8a8870b2 100644 --- a/executor/linux/build_test.go +++ b/executor/linux/build_test.go @@ -8,24 +8,23 @@ import ( "context" "flag" "net/http/httptest" + "strings" "testing" "time" + "github.com/gin-gonic/gin" + "github.com/go-vela/sdk-go/vela" "github.com/go-vela/server/compiler/native" "github.com/go-vela/server/mock/server" - "github.com/urfave/cli/v2" - - "github.com/go-vela/worker/internal/message" - "github.com/go-vela/worker/runtime" - "github.com/go-vela/worker/runtime/docker" - - "github.com/go-vela/sdk-go/vela" - "github.com/go-vela/types/constants" "github.com/go-vela/types/library" "github.com/go-vela/types/pipeline" - - "github.com/gin-gonic/gin" + "github.com/go-vela/worker/internal/message" + "github.com/go-vela/worker/runtime" + "github.com/go-vela/worker/runtime/docker" + "github.com/sirupsen/logrus" + logrusTest "github.com/sirupsen/logrus/hooks/test" + "github.com/urfave/cli/v2" ) func TestLinux_CreateBuild(t *testing.T) { @@ -37,6 +36,9 @@ func TestLinux_CreateBuild(t *testing.T) { _user := testUser() _metadata := testMetadata() + testLogger := logrus.New() + loggerHook := logrusTest.NewLocal(testLogger) + gin.SetMode(gin.TestMode) s := httptest.NewServer(server.FakeHandler()) @@ -49,6 +51,7 @@ func TestLinux_CreateBuild(t *testing.T) { tests := []struct { name string failure bool + logError bool runtime string build *library.Build pipeline string @@ -56,6 +59,7 @@ func TestLinux_CreateBuild(t *testing.T) { { name: "docker-basic secrets pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, build: _build, pipeline: "testdata/build/secrets/basic.yml", @@ -63,6 +67,7 @@ func TestLinux_CreateBuild(t *testing.T) { { name: "docker-basic services pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, build: _build, pipeline: "testdata/build/services/basic.yml", @@ -70,6 +75,7 @@ func TestLinux_CreateBuild(t *testing.T) { { name: "docker-basic steps pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, build: _build, pipeline: "testdata/build/steps/basic.yml", @@ -77,6 +83,7 @@ func TestLinux_CreateBuild(t *testing.T) { { name: "docker-basic stages pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, build: _build, pipeline: "testdata/build/stages/basic.yml", @@ -84,6 +91,7 @@ func TestLinux_CreateBuild(t *testing.T) { { name: "docker-steps pipeline with empty build", failure: true, + logError: false, runtime: constants.DriverDocker, build: new(library.Build), pipeline: "testdata/build/steps/basic.yml", @@ -93,6 +101,9 @@ func TestLinux_CreateBuild(t *testing.T) { // run test for _, test := range tests { t.Run(test.name, func(t *testing.T) { + logger := testLogger.WithFields(logrus.Fields{"test": test.name}) + defer loggerHook.Reset() + _pipeline, _, err := compiler. Duplicate(). WithBuild(_build). @@ -115,6 +126,7 @@ func TestLinux_CreateBuild(t *testing.T) { } _engine, err := New( + WithLogger(logger), WithBuild(test.build), WithPipeline(_pipeline), WithRepo(_repo), @@ -139,6 +151,21 @@ func TestLinux_CreateBuild(t *testing.T) { if err != nil { t.Errorf("%s CreateBuild returned err: %v", test.name, err) } + + loggedError := false + for _, logEntry := range loggerHook.AllEntries() { + // Many errors during StreamBuild get logged and ignored. + // So, Make sure there are no errors logged during StreamBuild. + if logEntry.Level == logrus.ErrorLevel { + loggedError = true + if !test.logError { + t.Errorf("%s StreamBuild for %s logged an Error: %v", test.name, test.pipeline, logEntry.Message) + } + } + } + if test.logError && !loggedError { + t.Errorf("%s StreamBuild for %s did not log an Error but should have", test.name, test.pipeline) + } }) } } @@ -981,6 +1008,9 @@ func TestLinux_PlanBuild(t *testing.T) { _user := testUser() _metadata := testMetadata() + testLogger := logrus.New() + loggerHook := logrusTest.NewLocal(testLogger) + gin.SetMode(gin.TestMode) s := httptest.NewServer(server.FakeHandler()) @@ -993,30 +1023,35 @@ func TestLinux_PlanBuild(t *testing.T) { tests := []struct { name string failure bool + logError bool runtime string pipeline string }{ { name: "docker-basic secrets pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/secrets/basic.yml", }, { name: "docker-basic services pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/services/basic.yml", }, { name: "docker-basic steps pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/steps/basic.yml", }, { name: "docker-basic stages pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/stages/basic.yml", }, @@ -1025,6 +1060,9 @@ func TestLinux_PlanBuild(t *testing.T) { // run test for _, test := range tests { t.Run(test.name, func(t *testing.T) { + logger := testLogger.WithFields(logrus.Fields{"test": test.name}) + defer loggerHook.Reset() + _pipeline, _, err := compiler. Duplicate(). WithBuild(_build). @@ -1047,6 +1085,7 @@ func TestLinux_PlanBuild(t *testing.T) { } _engine, err := New( + WithLogger(logger), WithBuild(_build), WithPipeline(_pipeline), WithRepo(_repo), @@ -1077,6 +1116,21 @@ func TestLinux_PlanBuild(t *testing.T) { if err != nil { t.Errorf("%s PlanBuild returned err: %v", test.name, err) } + + loggedError := false + for _, logEntry := range loggerHook.AllEntries() { + // Many errors during StreamBuild get logged and ignored. + // So, Make sure there are no errors logged during StreamBuild. + if logEntry.Level == logrus.ErrorLevel { + loggedError = true + if !test.logError { + t.Errorf("%s StreamBuild for %s logged an Error: %v", test.name, test.pipeline, logEntry.Message) + } + } + } + if test.logError && !loggedError { + t.Errorf("%s StreamBuild for %s did not log an Error but should have", test.name, test.pipeline) + } }) } } @@ -1090,6 +1144,9 @@ func TestLinux_AssembleBuild(t *testing.T) { _user := testUser() _metadata := testMetadata() + testLogger := logrus.New() + loggerHook := logrusTest.NewLocal(testLogger) + gin.SetMode(gin.TestMode) s := httptest.NewServer(server.FakeHandler()) @@ -1105,78 +1162,91 @@ func TestLinux_AssembleBuild(t *testing.T) { tests := []struct { name string failure bool + logError bool runtime string pipeline string }{ { name: "docker-basic secrets pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/secrets/basic.yml", }, { name: "docker-secrets pipeline with image not found", failure: true, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/secrets/img_notfound.yml", }, { name: "docker-secrets pipeline with ignoring image not found", failure: true, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/secrets/img_ignorenotfound.yml", }, { name: "docker-basic services pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/services/basic.yml", }, { name: "docker-services pipeline with image not found", failure: true, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/services/img_notfound.yml", }, { name: "docker-services pipeline with ignoring image not found", failure: true, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/services/img_ignorenotfound.yml", }, { name: "docker-basic steps pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/steps/basic.yml", }, { name: "docker-steps pipeline with image not found", failure: true, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/steps/img_notfound.yml", }, { name: "docker-steps pipeline with ignoring image not found", failure: true, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/steps/img_ignorenotfound.yml", }, { name: "docker-basic stages pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/stages/basic.yml", }, { name: "docker-stages pipeline with image not found", failure: true, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/stages/img_notfound.yml", }, { name: "docker-stages pipeline with ignoring image not found", failure: true, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/stages/img_ignorenotfound.yml", }, @@ -1185,6 +1255,9 @@ func TestLinux_AssembleBuild(t *testing.T) { // run test for _, test := range tests { t.Run(test.name, func(t *testing.T) { + logger := testLogger.WithFields(logrus.Fields{"test": test.name}) + defer loggerHook.Reset() + _pipeline, _, err := compiler. Duplicate(). WithBuild(_build). @@ -1207,6 +1280,7 @@ func TestLinux_AssembleBuild(t *testing.T) { } _engine, err := New( + WithLogger(logger), WithBuild(_build), WithPipeline(_pipeline), WithRepo(_repo), @@ -1238,6 +1312,21 @@ func TestLinux_AssembleBuild(t *testing.T) { if err != nil { t.Errorf("%s AssembleBuild returned err: %v", test.name, err) } + + loggedError := false + for _, logEntry := range loggerHook.AllEntries() { + // Many errors during StreamBuild get logged and ignored. + // So, Make sure there are no errors logged during StreamBuild. + if logEntry.Level == logrus.ErrorLevel { + loggedError = true + if !test.logError { + t.Errorf("%s StreamBuild for %s logged an Error: %v", test.name, test.pipeline, logEntry.Message) + } + } + } + if test.logError && !loggedError { + t.Errorf("%s StreamBuild for %s did not log an Error but should have", test.name, test.pipeline) + } }) } } @@ -1251,6 +1340,9 @@ func TestLinux_ExecBuild(t *testing.T) { _user := testUser() _metadata := testMetadata() + testLogger := logrus.New() + loggerHook := logrusTest.NewLocal(testLogger) + gin.SetMode(gin.TestMode) s := httptest.NewServer(server.FakeHandler()) @@ -1263,42 +1355,49 @@ func TestLinux_ExecBuild(t *testing.T) { tests := []struct { name string failure bool + logError bool runtime string pipeline string }{ { name: "docker-basic services pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/services/basic.yml", }, { name: "docker-services pipeline with image not found", failure: true, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/services/img_notfound.yml", }, { name: "docker-basic steps pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/steps/basic.yml", }, { name: "docker-steps pipeline with image not found", failure: true, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/steps/img_notfound.yml", }, { name: "docker-basic stages pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/stages/basic.yml", }, { name: "docker-stages pipeline with image not found", failure: true, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/stages/img_notfound.yml", }, @@ -1307,6 +1406,9 @@ func TestLinux_ExecBuild(t *testing.T) { // run test for _, test := range tests { t.Run(test.name, func(t *testing.T) { + logger := testLogger.WithFields(logrus.Fields{"test": test.name}) + defer loggerHook.Reset() + _pipeline, _, err := compiler. Duplicate(). WithBuild(_build). @@ -1332,6 +1434,7 @@ func TestLinux_ExecBuild(t *testing.T) { defer done() _engine, err := New( + WithLogger(logger), WithBuild(_build), WithPipeline(_pipeline), WithRepo(_repo), @@ -1397,6 +1500,21 @@ func TestLinux_ExecBuild(t *testing.T) { if err != nil { t.Errorf("%s ExecBuild for %s returned err: %v", test.name, test.pipeline, err) } + + loggedError := false + for _, logEntry := range loggerHook.AllEntries() { + // Many errors during StreamBuild get logged and ignored. + // So, Make sure there are no errors logged during StreamBuild. + if logEntry.Level == logrus.ErrorLevel { + loggedError = true + if !test.logError { + t.Errorf("%s StreamBuild for %s logged an Error: %v", test.name, test.pipeline, logEntry.Message) + } + } + } + if test.logError && !loggedError { + t.Errorf("%s StreamBuild for %s did not log an Error but should have", test.name, test.pipeline) + } }) } } @@ -1410,6 +1528,9 @@ func TestLinux_StreamBuild(t *testing.T) { _user := testUser() _metadata := testMetadata() + testLogger := logrus.New() + loggerHook := logrusTest.NewLocal(testLogger) + gin.SetMode(gin.TestMode) s := httptest.NewServer(server.FakeHandler()) @@ -1429,9 +1550,10 @@ func TestLinux_StreamBuild(t *testing.T) { tests := []struct { name string failure bool - runtime string earlyExecExit bool earlyBuildDone bool + logError bool + runtime string pipeline string msgCount int messageKey string @@ -1442,6 +1564,7 @@ func TestLinux_StreamBuild(t *testing.T) { { name: "docker-basic services pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/services/basic.yml", messageKey: "service", @@ -1466,6 +1589,7 @@ func TestLinux_StreamBuild(t *testing.T) { { name: "docker-basic services pipeline with StreamService failure", failure: false, + logError: true, runtime: constants.DriverDocker, pipeline: "testdata/build/services/basic.yml", messageKey: "service", @@ -1491,6 +1615,7 @@ func TestLinux_StreamBuild(t *testing.T) { { name: "docker-basic steps pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/steps/basic.yml", messageKey: "step", @@ -1513,6 +1638,7 @@ func TestLinux_StreamBuild(t *testing.T) { { name: "docker-basic steps pipeline with StreamStep failure", failure: false, + logError: true, runtime: constants.DriverDocker, pipeline: "testdata/build/steps/basic.yml", messageKey: "step", @@ -1536,6 +1662,7 @@ func TestLinux_StreamBuild(t *testing.T) { { name: "docker-basic stages pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/stages/basic.yml", messageKey: "step", @@ -1558,6 +1685,7 @@ func TestLinux_StreamBuild(t *testing.T) { { name: "docker-basic secrets pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/secrets/basic.yml", messageKey: "secret", @@ -1582,6 +1710,7 @@ func TestLinux_StreamBuild(t *testing.T) { name: "docker-early exit from ExecBuild", failure: false, earlyExecExit: true, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/steps/basic.yml", messageKey: "step", @@ -1605,6 +1734,7 @@ func TestLinux_StreamBuild(t *testing.T) { name: "docker-build complete before ExecBuild called", failure: false, earlyBuildDone: true, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/steps/basic.yml", messageKey: "step", @@ -1628,6 +1758,7 @@ func TestLinux_StreamBuild(t *testing.T) { name: "docker-early exit from ExecBuild and build complete signaled", failure: false, earlyExecExit: true, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/steps/basic.yml", messageKey: "step", @@ -1655,6 +1786,9 @@ func TestLinux_StreamBuild(t *testing.T) { streamRequests := make(chan message.StreamRequest) + logger := testLogger.WithFields(logrus.Fields{"test": test.name}) + defer loggerHook.Reset() + _pipeline, _, err := compiler. Duplicate(). WithBuild(_build). @@ -1677,6 +1811,7 @@ func TestLinux_StreamBuild(t *testing.T) { } _engine, err := New( + WithLogger(logger), WithBuild(_build), WithPipeline(_pipeline), WithRepo(_repo), @@ -1746,6 +1881,21 @@ func TestLinux_StreamBuild(t *testing.T) { if err != nil { t.Errorf("%s StreamBuild for %s returned err: %v", test.name, test.pipeline, err) } + + loggedError := false + for _, logEntry := range loggerHook.AllEntries() { + // Many errors during StreamBuild get logged and ignored. + // So, Make sure there are no errors logged during StreamBuild. + if logEntry.Level == logrus.ErrorLevel { + loggedError = true + if !test.logError { + t.Errorf("%s StreamBuild for %s logged an Error: %v", test.name, test.pipeline, logEntry.Message) + } + } + } + if test.logError && !loggedError { + t.Errorf("%s StreamBuild for %s did not log an Error but should have", test.name, test.pipeline) + } }) } } @@ -1759,6 +1909,9 @@ func TestLinux_DestroyBuild(t *testing.T) { _user := testUser() _metadata := testMetadata() + testLogger := logrus.New() + loggerHook := logrusTest.NewLocal(testLogger) + gin.SetMode(gin.TestMode) s := httptest.NewServer(server.FakeHandler()) @@ -1771,54 +1924,63 @@ func TestLinux_DestroyBuild(t *testing.T) { tests := []struct { name string failure bool + logError bool runtime string pipeline string }{ { name: "docker-basic secrets pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/secrets/basic.yml", }, { name: "docker-secrets pipeline with name not found", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/secrets/name_notfound.yml", }, { name: "docker-basic services pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/services/basic.yml", }, { name: "docker-services pipeline with name not found", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/services/name_notfound.yml", }, { name: "docker-basic steps pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/steps/basic.yml", }, { name: "docker-steps pipeline with name not found", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/steps/name_notfound.yml", }, { name: "docker-basic stages pipeline", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/stages/basic.yml", }, { name: "docker-stages pipeline with name not found", failure: false, + logError: false, runtime: constants.DriverDocker, pipeline: "testdata/build/stages/name_notfound.yml", }, @@ -1827,6 +1989,9 @@ func TestLinux_DestroyBuild(t *testing.T) { // run test for _, test := range tests { t.Run(test.name, func(t *testing.T) { + logger := testLogger.WithFields(logrus.Fields{"test": test.name}) + defer loggerHook.Reset() + _pipeline, _, err := compiler. Duplicate(). WithBuild(_build). @@ -1849,6 +2014,7 @@ func TestLinux_DestroyBuild(t *testing.T) { } _engine, err := New( + WithLogger(logger), WithBuild(_build), WithPipeline(_pipeline), WithRepo(_repo), @@ -1879,6 +2045,35 @@ func TestLinux_DestroyBuild(t *testing.T) { if err != nil { t.Errorf("%s DestroyBuild returned err: %v", test.name, err) } + + loggedError := false + for _, logEntry := range loggerHook.AllEntries() { + // Many errors during StreamBuild get logged and ignored. + // So, Make sure there are no errors logged during StreamBuild. + if logEntry.Level == logrus.ErrorLevel { + // Ignore error from not mocking something in the VelaClient + if strings.HasPrefix(logEntry.Message, "unable to upload") || + (strings.HasPrefix(logEntry.Message, "unable to destroy") && + strings.Contains(logEntry.Message, "No such container") && + strings.HasSuffix(logEntry.Message, "_notfound")) { + // unable to upload final step state: Step 0 does not exist + // unable to upload service snapshot: Service 0 does not exist + // unable to destroy secret: Error: No such container: secret_github_octocat_1_notfound + // unable to destroy service: Error: No such container: service_github_octocat_1_notfound + // unable to destroy step: Error: No such container: github_octocat_1_test_notfound + // unable to destroy stage: Error: No such container: github_octocat_1_test_notfound + continue + } + + loggedError = true + if !test.logError { + t.Errorf("%s StreamBuild for %s logged an Error: %v", test.name, test.pipeline, logEntry.Message) + } + } + } + if test.logError && !loggedError { + t.Errorf("%s StreamBuild for %s did not log an Error but should have", test.name, test.pipeline) + } }) } }