From db519aef670a83ef0308d1c58a5af5140448ec37 Mon Sep 17 00:00:00 2001 From: Morgan Tocker Date: Fri, 18 Oct 2019 13:12:19 -0600 Subject: [PATCH 1/5] Cat error log when mysqld fails to start Signed-off-by: Morgan Tocker --- go/vt/mysqlctl/mysqld.go | 15 ++++++++++++--- 1 file changed, 12 insertions(+), 3 deletions(-) diff --git a/go/vt/mysqlctl/mysqld.go b/go/vt/mysqlctl/mysqld.go index e8c85797ae8..4ec295ad43b 100644 --- a/go/vt/mysqlctl/mysqld.go +++ b/go/vt/mysqlctl/mysqld.go @@ -647,7 +647,7 @@ func (mysqld *Mysqld) Init(ctx context.Context, cnf *Mycnf, initDBSQLFile string // Start mysqld. We do not use Start, as we have to wait using // the root user. if err = mysqld.startNoWait(ctx, cnf); err != nil { - log.Errorf("failed starting mysqld (check mysql error log %v for more info): %v", cnf.ErrorLogPath, err) + log.Errorf("failed starting mysqld: %v %s", err, readMysqldErrorLog(cnf.ErrorLogPath)) return err } @@ -659,7 +659,7 @@ func (mysqld *Mysqld) Init(ctx context.Context, cnf *Mycnf, initDBSQLFile string UnixSocket: cnf.SocketFile, } if err = mysqld.wait(ctx, cnf, params); err != nil { - log.Errorf("failed starting mysqld in time (check mysyql error log %v for more info): %v", cnf.ErrorLogPath, err) + log.Errorf("failed starting mysqld in time: %v %s", err, readMysqldErrorLog(cnf.ErrorLogPath)) return err } @@ -676,6 +676,14 @@ func (mysqld *Mysqld) Init(ctx context.Context, cnf *Mycnf, initDBSQLFile string return nil } +func readMysqldErrorLog(fileName string) string { + b, err := ioutil.ReadFile(fileName) + if err != nil { // its already an error, return empty if we can't open + return "" + } + return string(b) +} + func (mysqld *Mysqld) installDataDir(cnf *Mycnf) error { mysqlRoot, err := vtenv.VtMysqlRoot() if err != nil { @@ -697,8 +705,9 @@ func (mysqld *Mysqld) installDataDir(cnf *Mycnf) error { "--basedir=" + mysqlBaseDir, "--initialize-insecure", // Use empty 'root'@'localhost' password. } + if _, _, err = execCmd(mysqldPath, args, nil, mysqlRoot, nil); err != nil { - log.Errorf("mysqld --initialize-insecure failed: %v", err) + log.Errorf("mysqld --initialize-insecure failed: %v %s", err, readMysqldErrorLog(cnf.ErrorLogPath)) return err } return nil From 7a15014f5df769d5f19e51063367749220e888ca Mon Sep 17 00:00:00 2001 From: Morgan Tocker Date: Wed, 23 Oct 2019 14:38:57 -0600 Subject: [PATCH 2/5] Incorporate feedback from review Signed-off-by: Morgan Tocker --- go/vt/mysqlctl/mysqld.go | 37 +++++++++++++++++++++++++++++-------- 1 file changed, 29 insertions(+), 8 deletions(-) diff --git a/go/vt/mysqlctl/mysqld.go b/go/vt/mysqlctl/mysqld.go index 4ec295ad43b..6250be591b9 100644 --- a/go/vt/mysqlctl/mysqld.go +++ b/go/vt/mysqlctl/mysqld.go @@ -81,6 +81,9 @@ var ( appMysqlStats = stats.NewTimings("MysqlApp", "MySQL app stats", "operation") versionRegex = regexp.MustCompile(`Ver ([0-9]+)\.([0-9]+)\.([0-9]+)`) + + // How many bytes from MySQL error log to sample for error messages + maxLogFileSampleSize = int64(4096) ) // Mysqld is the object that represents a mysqld daemon running on this server. @@ -647,7 +650,7 @@ func (mysqld *Mysqld) Init(ctx context.Context, cnf *Mycnf, initDBSQLFile string // Start mysqld. We do not use Start, as we have to wait using // the root user. if err = mysqld.startNoWait(ctx, cnf); err != nil { - log.Errorf("failed starting mysqld: %v %s", err, readMysqldErrorLog(cnf.ErrorLogPath)) + log.Errorf("failed starting mysqld: %v %s", err, readTailOfMysqldErrorLog(cnf.ErrorLogPath)) return err } @@ -659,7 +662,7 @@ func (mysqld *Mysqld) Init(ctx context.Context, cnf *Mycnf, initDBSQLFile string UnixSocket: cnf.SocketFile, } if err = mysqld.wait(ctx, cnf, params); err != nil { - log.Errorf("failed starting mysqld in time: %v %s", err, readMysqldErrorLog(cnf.ErrorLogPath)) + log.Errorf("failed starting mysqld in time: %v %s", err, readTailOfMysqldErrorLog(cnf.ErrorLogPath)) return err } @@ -676,12 +679,30 @@ func (mysqld *Mysqld) Init(ctx context.Context, cnf *Mycnf, initDBSQLFile string return nil } -func readMysqldErrorLog(fileName string) string { - b, err := ioutil.ReadFile(fileName) - if err != nil { // its already an error, return empty if we can't open - return "" +// For debugging purposes show the last few lines of the MySQL error log. +// Return a suggestion (string) if the file is non regular or can not be opened. +// This helps prevent cases where the error log is symlinked to /dev/stderr etc, +// In which case the user can manually open the file. +func readTailOfMysqldErrorLog(fileName string) string { + file, err := os.Open(fileName) + buf := make([]byte, maxLogFileSampleSize) + if err != nil { + return fmt.Sprintf("could not open mysql error log: %s", fileName) + } + fileInfo, err := file.Stat() + if err != nil || !fileInfo.Mode().IsRegular() { + return fmt.Sprintf("mysql error log file is not a regular file: %s", fileName) + } + startPos := int64(0) + if fileInfo.Size() > maxLogFileSampleSize { + startPos = fileInfo.Size() - maxLogFileSampleSize + } + // Show the last few KB of the MySQL error log. + flen, _ := file.ReadAt(buf, startPos) + if err != nil && err != io.EOF { + return fmt.Sprintf("could not read mysql error log: %s", fileName) } - return string(b) + return fmt.Sprintf("tail of mysql error log '%s':\n%s", fileName, buf[:flen]) } func (mysqld *Mysqld) installDataDir(cnf *Mycnf) error { @@ -707,7 +728,7 @@ func (mysqld *Mysqld) installDataDir(cnf *Mycnf) error { } if _, _, err = execCmd(mysqldPath, args, nil, mysqlRoot, nil); err != nil { - log.Errorf("mysqld --initialize-insecure failed: %v %s", err, readMysqldErrorLog(cnf.ErrorLogPath)) + log.Errorf("mysqld --initialize-insecure failed: %v %s", err, readTailOfMysqldErrorLog(cnf.ErrorLogPath)) return err } return nil From f7a4b86e7f255de673e59ec1a79db395fe662ad5 Mon Sep 17 00:00:00 2001 From: Morgan Tocker Date: Wed, 23 Oct 2019 14:41:28 -0600 Subject: [PATCH 3/5] Remove added space Signed-off-by: Morgan Tocker --- go/vt/mysqlctl/mysqld.go | 1 - 1 file changed, 1 deletion(-) diff --git a/go/vt/mysqlctl/mysqld.go b/go/vt/mysqlctl/mysqld.go index 6250be591b9..9cdebea3cdf 100644 --- a/go/vt/mysqlctl/mysqld.go +++ b/go/vt/mysqlctl/mysqld.go @@ -726,7 +726,6 @@ func (mysqld *Mysqld) installDataDir(cnf *Mycnf) error { "--basedir=" + mysqlBaseDir, "--initialize-insecure", // Use empty 'root'@'localhost' password. } - if _, _, err = execCmd(mysqldPath, args, nil, mysqlRoot, nil); err != nil { log.Errorf("mysqld --initialize-insecure failed: %v %s", err, readTailOfMysqldErrorLog(cnf.ErrorLogPath)) return err From 6d821f9afd56b7c4b0e858fee1636b341fbe1af7 Mon Sep 17 00:00:00 2001 From: Morgan Tocker Date: Thu, 24 Oct 2019 07:22:36 -0600 Subject: [PATCH 4/5] Address PR Feedback Signed-off-by: Morgan Tocker --- go/vt/mysqlctl/mysqld.go | 32 ++++++++++++++++++-------------- 1 file changed, 18 insertions(+), 14 deletions(-) diff --git a/go/vt/mysqlctl/mysqld.go b/go/vt/mysqlctl/mysqld.go index 9cdebea3cdf..379dbc37d2a 100644 --- a/go/vt/mysqlctl/mysqld.go +++ b/go/vt/mysqlctl/mysqld.go @@ -81,11 +81,11 @@ var ( appMysqlStats = stats.NewTimings("MysqlApp", "MySQL app stats", "operation") versionRegex = regexp.MustCompile(`Ver ([0-9]+)\.([0-9]+)\.([0-9]+)`) - - // How many bytes from MySQL error log to sample for error messages - maxLogFileSampleSize = int64(4096) ) +// How many bytes from MySQL error log to sample for error messages +const maxLogFileSampleSize = 4096 + // Mysqld is the object that represents a mysqld daemon running on this server. type Mysqld struct { dbcfgs *dbconfigs.DBConfigs @@ -650,7 +650,7 @@ func (mysqld *Mysqld) Init(ctx context.Context, cnf *Mycnf, initDBSQLFile string // Start mysqld. We do not use Start, as we have to wait using // the root user. if err = mysqld.startNoWait(ctx, cnf); err != nil { - log.Errorf("failed starting mysqld: %v %s", err, readTailOfMysqldErrorLog(cnf.ErrorLogPath)) + log.Errorf("failed starting mysqld: %v\n%v", err, readTailOfMysqldErrorLog(cnf.ErrorLogPath)) return err } @@ -662,7 +662,7 @@ func (mysqld *Mysqld) Init(ctx context.Context, cnf *Mycnf, initDBSQLFile string UnixSocket: cnf.SocketFile, } if err = mysqld.wait(ctx, cnf, params); err != nil { - log.Errorf("failed starting mysqld in time: %v %s", err, readTailOfMysqldErrorLog(cnf.ErrorLogPath)) + log.Errorf("failed starting mysqld in time: %v\n%v", err, readTailOfMysqldErrorLog(cnf.ErrorLogPath)) return err } @@ -685,24 +685,28 @@ func (mysqld *Mysqld) Init(ctx context.Context, cnf *Mycnf, initDBSQLFile string // In which case the user can manually open the file. func readTailOfMysqldErrorLog(fileName string) string { file, err := os.Open(fileName) - buf := make([]byte, maxLogFileSampleSize) + defer file.Close() if err != nil { - return fmt.Sprintf("could not open mysql error log: %s", fileName) + return fmt.Sprintf("could not open mysql error log (%v): %v", fileName, err) } fileInfo, err := file.Stat() - if err != nil || !fileInfo.Mode().IsRegular() { - return fmt.Sprintf("mysql error log file is not a regular file: %s", fileName) + if err != nil { + return fmt.Sprintf("could not stat mysql error log (%v): %v", fileName, err) + } + if !fileInfo.Mode().IsRegular() { + return fmt.Sprintf("mysql error log file is not a regular file: %v", fileName) } startPos := int64(0) if fileInfo.Size() > maxLogFileSampleSize { startPos = fileInfo.Size() - maxLogFileSampleSize } // Show the last few KB of the MySQL error log. - flen, _ := file.ReadAt(buf, startPos) + buf := make([]byte, maxLogFileSampleSize) + flen, err := file.ReadAt(buf, startPos) if err != nil && err != io.EOF { - return fmt.Sprintf("could not read mysql error log: %s", fileName) + return fmt.Sprintf("could not read mysql error log (%v): %v", fileName, err) } - return fmt.Sprintf("tail of mysql error log '%s':\n%s", fileName, buf[:flen]) + return fmt.Sprintf("tail of mysql error log (%v):\n%s", fileName, buf[:flen]) } func (mysqld *Mysqld) installDataDir(cnf *Mycnf) error { @@ -727,7 +731,7 @@ func (mysqld *Mysqld) installDataDir(cnf *Mycnf) error { "--initialize-insecure", // Use empty 'root'@'localhost' password. } if _, _, err = execCmd(mysqldPath, args, nil, mysqlRoot, nil); err != nil { - log.Errorf("mysqld --initialize-insecure failed: %v %s", err, readTailOfMysqldErrorLog(cnf.ErrorLogPath)) + log.Errorf("mysqld --initialize-insecure failed: %v\n%v", err, readTailOfMysqldErrorLog(cnf.ErrorLogPath)) return err } return nil @@ -743,7 +747,7 @@ func (mysqld *Mysqld) installDataDir(cnf *Mycnf) error { return err } if _, _, err = execCmd(cmdPath, args, nil, mysqlRoot, nil); err != nil { - log.Errorf("mysql_install_db failed: %v", err) + log.Errorf("mysql_install_db failed: %v\n%v", err, readTailOfMysqldErrorLog(cnf.ErrorLogPath)) return err } return nil From 8f1b94672993e3e69b60aadc7a1478b4dcd54622 Mon Sep 17 00:00:00 2001 From: Morgan Tocker Date: Thu, 24 Oct 2019 07:35:04 -0600 Subject: [PATCH 5/5] Address PR Feedback Signed-off-by: Morgan Tocker --- go/vt/mysqlctl/mysqld.go | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/go/vt/mysqlctl/mysqld.go b/go/vt/mysqlctl/mysqld.go index 379dbc37d2a..fdc60ca77f7 100644 --- a/go/vt/mysqlctl/mysqld.go +++ b/go/vt/mysqlctl/mysqld.go @@ -684,18 +684,18 @@ func (mysqld *Mysqld) Init(ctx context.Context, cnf *Mycnf, initDBSQLFile string // This helps prevent cases where the error log is symlinked to /dev/stderr etc, // In which case the user can manually open the file. func readTailOfMysqldErrorLog(fileName string) string { - file, err := os.Open(fileName) - defer file.Close() - if err != nil { - return fmt.Sprintf("could not open mysql error log (%v): %v", fileName, err) - } - fileInfo, err := file.Stat() + fileInfo, err := os.Stat(fileName) if err != nil { return fmt.Sprintf("could not stat mysql error log (%v): %v", fileName, err) } if !fileInfo.Mode().IsRegular() { return fmt.Sprintf("mysql error log file is not a regular file: %v", fileName) } + file, err := os.Open(fileName) + if err != nil { + return fmt.Sprintf("could not open mysql error log (%v): %v", fileName, err) + } + defer file.Close() startPos := int64(0) if fileInfo.Size() > maxLogFileSampleSize { startPos = fileInfo.Size() - maxLogFileSampleSize