From 2736d62d471ca1275161501081f262073840782e Mon Sep 17 00:00:00 2001 From: Anna Shaleva Date: Mon, 7 Feb 2022 18:51:54 +0300 Subject: [PATCH] cli: ensure opened sinks are properly closed zap never closes open sinks except its own tests. This behaviour prevents TestHandleLoggingParams from successful cleanup because temp log output file can't be closed due to the following error: ``` TempDir RemoveAll cleanup: remove C:\\Users\\Anna\\AppData\\Local\\Temp\\TestHandleLoggingParams_debug5796883 33\\001\\file.log: The process cannot access the file because it is being used by another process. ``` So this tremendous cludge is made mosetly for our testing code. It is not for concurrent usage (we don't have cases of multithreaded access to logger output sink). --- cli/server/server.go | 42 +++++++++++++++++++++++++++++---------- cli/server/server_test.go | 24 ++++++++++++++++++---- 2 files changed, 51 insertions(+), 15 deletions(-) diff --git a/cli/server/server.go b/cli/server/server.go index 36bfd1c47..310fada08 100644 --- a/cli/server/server.go +++ b/cli/server/server.go @@ -31,9 +31,12 @@ import ( "go.uber.org/zap/zapcore" ) -// _winfileSinkRegistered denotes whether zap has registered -// user-supplied factory for all sinks with `winfile`-prefixed scheme. -var _winfileSinkRegistered bool +var ( + // _winfileSinkRegistered denotes whether zap has registered + // user-supplied factory for all sinks with `winfile`-prefixed scheme. + _winfileSinkRegistered bool + _winfileSinkCloser func() error +) // NewCommands returns 'node' command. func NewCommands() []cli.Command { @@ -130,7 +133,9 @@ func getConfigFromContext(ctx *cli.Context) (config.Config, error) { // handleLoggingParams reads logging parameters. // If user selected debug level -- function enables it. // If logPath is configured -- function creates dir and file for logging. -func handleLoggingParams(ctx *cli.Context, cfg config.ApplicationConfiguration) (*zap.Logger, error) { +// If logPath is configured on Windows -- function returns closer to be +// able to close sink for opened log output file. +func handleLoggingParams(ctx *cli.Context, cfg config.ApplicationConfiguration) (*zap.Logger, func() error, error) { level := zapcore.InfoLevel if ctx.Bool("debug") { level = zapcore.DebugLevel @@ -148,7 +153,7 @@ func handleLoggingParams(ctx *cli.Context, cfg config.ApplicationConfiguration) if logPath := cfg.LogPath; logPath != "" { if err := io.MakeDirForFile(logPath, "logger"); err != nil { - return nil, err + return nil, nil, err } if runtime.GOOS == "windows" { @@ -177,11 +182,16 @@ func handleLoggingParams(ctx *cli.Context, cfg config.ApplicationConfiguration) case "stderr": return os.Stderr, nil } - return os.OpenFile(u.Path[1:], // Remove leading slash left after url.Parse. + f, err := os.OpenFile(u.Path[1:], // Remove leading slash left after url.Parse. os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0644) + _winfileSinkCloser = func() error { + _winfileSinkCloser = nil + return f.Close() + } + return f, err }) if err != nil { - return nil, fmt.Errorf("failed to register windows-specific sinc: %w", err) + return nil, nil, fmt.Errorf("failed to register windows-specific sinc: %w", err) } _winfileSinkRegistered = true } @@ -191,7 +201,8 @@ func handleLoggingParams(ctx *cli.Context, cfg config.ApplicationConfiguration) cc.OutputPaths = []string{logPath} } - return cc.Build() + log, err := cc.Build() + return log, _winfileSinkCloser, err } func initBCWithMetrics(cfg config.Config, log *zap.Logger) (*core.Blockchain, *metrics.Service, *metrics.Service, error) { @@ -215,10 +226,13 @@ func dumpDB(ctx *cli.Context) error { if err != nil { return cli.NewExitError(err, 1) } - log, err := handleLoggingParams(ctx, cfg.ApplicationConfiguration) + log, logCloser, err := handleLoggingParams(ctx, cfg.ApplicationConfiguration) if err != nil { return cli.NewExitError(err, 1) } + if logCloser != nil { + defer func() { _ = logCloser() }() + } count := uint32(ctx.Uint("count")) start := uint32(ctx.Uint("start")) @@ -262,10 +276,13 @@ func restoreDB(ctx *cli.Context) error { if err != nil { return err } - log, err := handleLoggingParams(ctx, cfg.ApplicationConfiguration) + log, logCloser, err := handleLoggingParams(ctx, cfg.ApplicationConfiguration) if err != nil { return cli.NewExitError(err, 1) } + if logCloser != nil { + defer func() { _ = logCloser() }() + } count := uint32(ctx.Uint("count")) var inStream = os.Stdin @@ -438,10 +455,13 @@ func startServer(ctx *cli.Context) error { if err != nil { return cli.NewExitError(err, 1) } - log, err := handleLoggingParams(ctx, cfg.ApplicationConfiguration) + log, logCloser, err := handleLoggingParams(ctx, cfg.ApplicationConfiguration) if err != nil { return cli.NewExitError(err, 1) } + if logCloser != nil { + defer func() { _ = logCloser() }() + } grace, cancel := context.WithCancel(newGraceContext()) defer cancel() diff --git a/cli/server/server_test.go b/cli/server/server_test.go index 3165e7037..88909d864 100644 --- a/cli/server/server_test.go +++ b/cli/server/server_test.go @@ -52,8 +52,9 @@ func TestHandleLoggingParams(t *testing.T) { cfg := config.ApplicationConfiguration{ LogPath: filepath.Join(logfile, "file.log"), } - _, err := handleLoggingParams(ctx, cfg) + _, closer, err := handleLoggingParams(ctx, cfg) require.Error(t, err) + require.Nil(t, closer) }) t.Run("default", func(t *testing.T) { @@ -62,8 +63,13 @@ func TestHandleLoggingParams(t *testing.T) { cfg := config.ApplicationConfiguration{ LogPath: testLog, } - logger, err := handleLoggingParams(ctx, cfg) + logger, closer, err := handleLoggingParams(ctx, cfg) require.NoError(t, err) + t.Cleanup(func() { + if closer != nil { + require.NoError(t, closer()) + } + }) require.True(t, logger.Core().Enabled(zap.InfoLevel)) require.False(t, logger.Core().Enabled(zap.DebugLevel)) }) @@ -75,8 +81,13 @@ func TestHandleLoggingParams(t *testing.T) { cfg := config.ApplicationConfiguration{ LogPath: testLog, } - logger, err := handleLoggingParams(ctx, cfg) + logger, closer, err := handleLoggingParams(ctx, cfg) require.NoError(t, err) + t.Cleanup(func() { + if closer != nil { + require.NoError(t, closer()) + } + }) require.True(t, logger.Core().Enabled(zap.InfoLevel)) require.True(t, logger.Core().Enabled(zap.DebugLevel)) }) @@ -95,8 +106,13 @@ func TestInitBCWithMetrics(t *testing.T) { ctx := cli.NewContext(cli.NewApp(), set, nil) cfg, err := getConfigFromContext(ctx) require.NoError(t, err) - logger, err := handleLoggingParams(ctx, cfg.ApplicationConfiguration) + logger, closer, err := handleLoggingParams(ctx, cfg.ApplicationConfiguration) require.NoError(t, err) + t.Cleanup(func() { + if closer != nil { + require.NoError(t, closer()) + } + }) t.Run("bad store", func(t *testing.T) { _, _, _, err = initBCWithMetrics(config.Config{}, logger)