From c489f975d4ae74511100fda47a6083f8b6fd4ec2 Mon Sep 17 00:00:00 2001 From: Roman Khimov Date: Thu, 25 Jun 2020 19:22:38 +0300 Subject: [PATCH 1/2] core: fix TestSubscriptions occasional failures panic: Log in goroutine after TestSubscriptions has completed goroutine 1079 [running]: testing.(*common).logDepth(0xc00057a100, 0xc00039e210, 0xa4, 0x3) /usr/local/go/src/testing/testing.go:634 +0x51a testing.(*common).log(...) /usr/local/go/src/testing/testing.go:614 testing.(*common).Logf(0xc00057a100, 0xe32eaa, 0x2, 0xc0009560e0, 0x1, 0x1) /usr/local/go/src/testing/testing.go:649 +0x91 go.uber.org/zap/zaptest.testingWriter.Write(0xf64120, 0xc00057a100, 0x0, 0xc0003fe400, 0xa5, 0x400, 0xc000958e40, 0xc0009560d0, 0xc000958e60) /go/pkg/mod/go.uber.org/zap@v1.10.0/zaptest/logger.go:130 +0x120 go.uber.org/zap/zapcore.(*ioCore).Write(0xc0005cd050, 0x0, 0xbfb54ffc0626aba2, 0x916de700, 0x1485500, 0x0, 0x0, 0xe43fb0, 0x1c, 0x0, ...) /go/pkg/mod/go.uber.org/zap@v1.10.0/zapcore/core.go:90 +0x1c5 go.uber.org/zap/zapcore.(*CheckedEntry).Write(0xc000102d10, 0xc00039a000, 0x5, 0x5) /go/pkg/mod/go.uber.org/zap@v1.10.0/zapcore/entry.go:215 +0x1e8 go.uber.org/zap.(*Logger).Info(0xc00035eba0, 0xe43fb0, 0x1c, 0xc00039a000, 0x5, 0x5) /go/pkg/mod/go.uber.org/zap@v1.10.0/logger.go:187 +0x96 github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).persist(0xc00000cb40, 0xc00017c2c0, 0xbe8a00) /go/src/github.com/nspcc-dev/neo-go/pkg/core/blockchain.go:839 +0x6c9 github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).Run.func2(0xc00000cb40, 0xc0005c6c30) /go/src/github.com/nspcc-dev/neo-go/pkg/core/blockchain.go:302 +0x54 created by github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).Run /go/src/github.com/nspcc-dev/neo-go/pkg/core/blockchain.go:301 +0x25d FAIL github.com/nspcc-dev/neo-go/pkg/core 2.463s --- pkg/core/blockchain_test.go | 1 + 1 file changed, 1 insertion(+) diff --git a/pkg/core/blockchain_test.go b/pkg/core/blockchain_test.go index d344671b5..5f06ab4d8 100644 --- a/pkg/core/blockchain_test.go +++ b/pkg/core/blockchain_test.go @@ -246,6 +246,7 @@ func TestSubscriptions(t *testing.T) { executionCh := make(chan *state.AppExecResult, chBufSize) bc := newTestChain(t) + defer bc.Close() bc.SubscribeForBlocks(blockCh) bc.SubscribeForTransactions(txCh) bc.SubscribeForNotifications(notificationCh) From 8f1ddc0651b6c4006f8bc03e0d4cb2c451da7e14 Mon Sep 17 00:00:00 2001 From: Roman Khimov Date: Thu, 25 Jun 2020 19:31:45 +0300 Subject: [PATCH 2/2] rpc/server: fix error reporting in Start This error message makes no sense when shutting down the server: 2020-06-25T19:29:53.251+0300 ERROR failed to start RPC server {"error": "http: Server closed"} And ListenAndServer is documented to always return non-nil error one of which is http.ErrServerClosed. This should also fix the following test failure: ================== WARNING: DATA RACE Read at 0x00c000254243 by goroutine 49: testing.(*common).logDepth() /usr/local/go/src/testing/testing.go:665 +0xa1 testing.(*common).Logf() /usr/local/go/src/testing/testing.go:658 +0x8f testing.(*T).Logf() :1 +0x75 go.uber.org/zap/zaptest.testingWriter.Write() /go/pkg/mod/go.uber.org/zap@v1.10.0/zaptest/logger.go:130 +0x11f go.uber.org/zap/zaptest.(*testingWriter).Write() :1 +0xa9 go.uber.org/zap/zapcore.(*ioCore).Write() /go/pkg/mod/go.uber.org/zap@v1.10.0/zapcore/core.go:90 +0x1c3 go.uber.org/zap/zapcore.(*CheckedEntry).Write() /go/pkg/mod/go.uber.org/zap@v1.10.0/zapcore/entry.go:215 +0x1e7 go.uber.org/zap.(*Logger).Error() /go/pkg/mod/go.uber.org/zap@v1.10.0/logger.go:203 +0x95 github.com/nspcc-dev/neo-go/pkg/rpc/server.(*Server).Start() /go/src/github.com/nspcc-dev/neo-go/pkg/rpc/server/server.go:179 +0x5c5 Previous write at 0x00c000254243 by goroutine 44: testing.tRunner.func1() /usr/local/go/src/testing/testing.go:900 +0x353 testing.tRunner() /usr/local/go/src/testing/testing.go:913 +0x1bb Goroutine 49 (running) created at: github.com/nspcc-dev/neo-go/pkg/rpc/server.initClearServerWithInMemoryChain() /go/src/github.com/nspcc-dev/neo-go/pkg/rpc/server/server_helper_test.go:69 +0x305 github.com/nspcc-dev/neo-go/pkg/rpc/server.initServerWithInMemoryChain() /go/src/github.com/nspcc-dev/neo-go/pkg/rpc/server/server_helper_test.go:78 +0x3c github.com/nspcc-dev/neo-go/pkg/rpc/server.testRPCProtocol() /go/src/github.com/nspcc-dev/neo-go/pkg/rpc/server/server_test.go:805 +0x53 github.com/nspcc-dev/neo-go/pkg/rpc/server.TestRPC.func1() /go/src/github.com/nspcc-dev/neo-go/pkg/rpc/server/server_test.go:793 +0x44 testing.tRunner() /usr/local/go/src/testing/testing.go:909 +0x199 Goroutine 44 (finished) created at: testing.(*T).Run() /usr/local/go/src/testing/testing.go:960 +0x651 github.com/nspcc-dev/neo-go/pkg/rpc/server.TestRPC() /go/src/github.com/nspcc-dev/neo-go/pkg/rpc/server/server_test.go:792 +0x5d testing.tRunner() /usr/local/go/src/testing/testing.go:909 +0x199 ================== --- pkg/rpc/server/server.go | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/pkg/rpc/server/server.go b/pkg/rpc/server/server.go index 675efc9b7..d6ecd4785 100644 --- a/pkg/rpc/server/server.go +++ b/pkg/rpc/server/server.go @@ -176,17 +176,17 @@ func (s *Server) Start(errChan chan error) { s.log.Info("starting rpc-server (https)", zap.String("endpoint", s.https.Addr)) go func() { err := s.https.ListenAndServeTLS(cfg.CertFile, cfg.KeyFile) - if err != nil { + if err != http.ErrServerClosed { s.log.Error("failed to start TLS RPC server", zap.Error(err)) + errChan <- err } - errChan <- err }() } err := s.ListenAndServe() - if err != nil { + if err != http.ErrServerClosed { s.log.Error("failed to start RPC server", zap.Error(err)) + errChan <- err } - errChan <- err } // Shutdown overrides the http.Server Shutdown