From 9c9e366a34abd50f5c1b8dbfa4df01a7bca8c5d8 Mon Sep 17 00:00:00 2001 From: MacKinley Smith Date: Sat, 25 Feb 2023 01:20:26 -0700 Subject: [PATCH] Include the contents of logs when postgres fails to start or initdb fails (#84) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * fix: print log contents when postgres fails to start * fix: flush the logger before attempting to read * test: failure is included in error when postgres fails to start * fix: include log contents with initialization errors * fix: flush the logger before reading * refactor: read by file name * test: logs are output on initialization failure * fix: os -> ioutil for older versions of Go * fix: os -> ioutil for older versions of Go * lint: stop cuddling 😆 * fix: bail if we can't read the logs after 10s * refactor: move log reading into function * refactor: use timeout version for startPostgres too * test: logging method * test: error case * test: logging method content * fix: imports * feat: include log reading error in log output --- embedded_postgres.go | 5 ++++- embedded_postgres_test.go | 3 ++- logging.go | 26 ++++++++++++++++++++++++++ logging_test.go | 25 +++++++++++++++++++++++++ prepare_database.go | 6 +++++- prepare_database_test.go | 15 ++++++++++++++- 6 files changed, 76 insertions(+), 4 deletions(-) diff --git a/embedded_postgres.go b/embedded_postgres.go index a72a3cb..966f130 100644 --- a/embedded_postgres.go +++ b/embedded_postgres.go @@ -188,7 +188,10 @@ func startPostgres(ep *EmbeddedPostgres) error { postgresProcess.Stderr = ep.syncedLogger.file if err := postgresProcess.Run(); err != nil { - return fmt.Errorf("could not start postgres using %s", postgresProcess.String()) + _ = ep.syncedLogger.flush() + logContent, _ := readLogsOrTimeout(ep.syncedLogger.file) + + return fmt.Errorf("could not start postgres using %s:\n%s", postgresProcess.String(), string(logContent)) } return nil diff --git a/embedded_postgres_test.go b/embedded_postgres_test.go index de25204..22212ee 100644 --- a/embedded_postgres_test.go +++ b/embedded_postgres_test.go @@ -226,12 +226,13 @@ func Test_ErrorWhenCannotStartPostgresProcess(t *testing.T) { } database.initDatabase = func(binaryExtractLocation, runtimePath, dataLocation, username, password, locale string, logger *os.File) error { + _, _ = logger.Write([]byte("ah it did not work")) return nil } err = database.Start() - assert.EqualError(t, err, fmt.Sprintf(`could not start postgres using %s/bin/pg_ctl start -w -D %s/data -o "-p 5432"`, extractPath, extractPath)) + assert.EqualError(t, err, fmt.Sprintf("could not start postgres using %s/bin/pg_ctl start -w -D %s/data -o \"-p 5432\":\nah it did not work", extractPath, extractPath)) } func Test_CustomConfig(t *testing.T) { diff --git a/logging.go b/logging.go index be54326..364e932 100644 --- a/logging.go +++ b/logging.go @@ -3,7 +3,9 @@ package embeddedpostgres import ( "fmt" "io" + "io/ioutil" "os" + "time" ) type syncedLogger struct { @@ -53,3 +55,27 @@ func (s *syncedLogger) flush() error { return nil } + +func readLogsOrTimeout(logger *os.File) (logContent []byte, err error) { + logContent = []byte("logs could not be read") + + logContentChan := make(chan []byte, 1) + errChan := make(chan error, 1) + + go func() { + if actualLogContent, err := ioutil.ReadFile(logger.Name()); err == nil { + logContentChan <- actualLogContent + } else { + errChan <- err + } + }() + + select { + case logContent = <-logContentChan: + case err = <-errChan: + case <-time.After(10 * time.Second): + err = fmt.Errorf("timed out waiting for logs") + } + + return logContent, err +} diff --git a/logging_test.go b/logging_test.go index 59cdb3a..c64b7d0 100644 --- a/logging_test.go +++ b/logging_test.go @@ -1,10 +1,13 @@ package embeddedpostgres import ( + "fmt" + "io/ioutil" "os" "testing" "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" ) type customLogger struct { @@ -56,3 +59,25 @@ func Test_SyncedLogger_NoErrorDuringFlush(t *testing.T) { assert.Equal(t, "some logs\non a new line", string(logger.logLines)) } + +func Test_readLogsOrTimeout(t *testing.T) { + logFile, err := ioutil.TempFile("", "prepare_database_test_log") + if err != nil { + panic(err) + } + + logContent, err := readLogsOrTimeout(logFile) + assert.NoError(t, err) + assert.Equal(t, []byte(""), logContent) + + _, _ = logFile.Write([]byte("and here are the logs!")) + + logContent, err = readLogsOrTimeout(logFile) + assert.NoError(t, err) + assert.Equal(t, []byte("and here are the logs!"), logContent) + + require.NoError(t, os.Remove(logFile.Name())) + logContent, err = readLogsOrTimeout(logFile) + assert.Equal(t, []byte("logs could not be read"), logContent) + assert.EqualError(t, err, fmt.Sprintf("open %s: no such file or directory", logFile.Name())) +} diff --git a/prepare_database.go b/prepare_database.go index 8e870a6..494be90 100644 --- a/prepare_database.go +++ b/prepare_database.go @@ -44,7 +44,11 @@ func defaultInitDatabase(binaryExtractLocation, runtimePath, pgDataDir, username postgresInitDBProcess.Stdout = logger if err = postgresInitDBProcess.Run(); err != nil { - return fmt.Errorf("unable to init database using '%s': %w", postgresInitDBProcess.String(), err) + logContent, readLogsErr := readLogsOrTimeout(logger) // we want to preserve the original error + if readLogsErr != nil { + logContent = []byte(string(logContent) + " - " + readLogsErr.Error()) + } + return fmt.Errorf("unable to init database using '%s': %w\n%s", postgresInitDBProcess.String(), err, string(logContent)) } if err = os.Remove(passwordFile); err != nil { diff --git a/prepare_database_test.go b/prepare_database_test.go index f2fa3d7..f29845b 100644 --- a/prepare_database_test.go +++ b/prepare_database_test.go @@ -3,6 +3,7 @@ package embeddedpostgres import ( "errors" "fmt" + "io/ioutil" "os" "path/filepath" "testing" @@ -27,6 +28,11 @@ func Test_defaultInitDatabase_ErrorWhenCannotStartInitDBProcess(t *testing.T) { panic(err) } + logFile, err := ioutil.TempFile("", "prepare_database_test_log") + if err != nil { + panic(err) + } + defer func() { if err := os.RemoveAll(binTempDir); err != nil { panic(err) @@ -35,15 +41,22 @@ func Test_defaultInitDatabase_ErrorWhenCannotStartInitDBProcess(t *testing.T) { if err := os.RemoveAll(runtimeTempDir); err != nil { panic(err) } + + if err := os.Remove(logFile.Name()); err != nil { + panic(err) + } }() - err = defaultInitDatabase(binTempDir, runtimeTempDir, filepath.Join(runtimeTempDir, "data"), "Tom", "Beer", "", os.Stderr) + _, _ = logFile.Write([]byte("and here are the logs!")) + + err = defaultInitDatabase(binTempDir, runtimeTempDir, filepath.Join(runtimeTempDir, "data"), "Tom", "Beer", "", logFile) assert.NotNil(t, err) assert.Contains(t, err.Error(), fmt.Sprintf("unable to init database using '%s/bin/initdb -A password -U Tom -D %s/data --pwfile=%s/pwfile'", binTempDir, runtimeTempDir, runtimeTempDir)) + assert.Contains(t, err.Error(), "and here are the logs!") assert.FileExists(t, filepath.Join(runtimeTempDir, "pwfile")) }