From 9a7f38fcdf1b1f87f9cb063ed46860599a8762eb Mon Sep 17 00:00:00 2001 From: Samuel Hawksby-Robinson Date: Wed, 19 Oct 2022 11:01:04 +0100 Subject: [PATCH] Added portManager debug logging --- server/ports.go | 33 +++++++++++++++++++++++++++++++-- server/server.go | 5 +++-- server/server_test.go | 7 +++++-- signal/events_messenger.go | 4 ++-- 4 files changed, 41 insertions(+), 8 deletions(-) diff --git a/server/ports.go b/server/ports.go index fb9c1a78e..a76eae3fb 100644 --- a/server/ports.go +++ b/server/ports.go @@ -3,6 +3,8 @@ package server import ( "fmt" "sync" + + "go.uber.org/zap" ) // portManager is responsible for maintaining segregated access to the port field @@ -10,6 +12,7 @@ import ( // rwLock establishes a standard read write mutex that allows consecutive reads and exclusive writes // mustRead forces MustGetPort to wait until port has a none 0 value type portManger struct { + logger *zap.Logger port int afterPortChanged func(port int) rwLock *sync.RWMutex @@ -17,8 +20,9 @@ type portManger struct { } // newPortManager returns a newly initialised portManager with a pre-Locked portManger.mustRead sync.Mutex -func newPortManager(afterPortChanged func(int)) portManger { +func newPortManager(logger *zap.Logger, afterPortChanged func(int)) portManger { pm := portManger{ + logger: logger.Named("portManger"), afterPortChanged: afterPortChanged, rwLock: new(sync.RWMutex), mustRead: new(sync.Mutex), @@ -31,18 +35,26 @@ func newPortManager(afterPortChanged func(int)) portManger { // next triggers any given portManger.afterPortChanged function // additionally portManger.mustRead.Unlock() is called, releasing any calls to MustGetPort func (p *portManger) SetPort(port int) error { + l := p.logger.Named("SetPort") + l.Debug("fired", zap.Int("port", port)) + p.rwLock.Lock() defer p.rwLock.Unlock() + l.Debug("acquired rwLock.Lock") if port == 0 { - return fmt.Errorf("port can not be `0`, use ResetPort() instead") + errMsg := "port can not be `0`, use ResetPort() instead" + l.Error(errMsg) + return fmt.Errorf(errMsg) } p.port = port if p.afterPortChanged != nil { + l.Debug("p.afterPortChanged != nil") p.afterPortChanged(port) } p.mustRead.Unlock() + l.Debug("p.mustRead.Unlock()") return nil } @@ -52,30 +64,47 @@ func (p *portManger) SetPort(port int) error { // and calling multiple times must not cause a deadlock or an infinite hang, but the lock needs to be // reapplied if it is not present. func (p *portManger) ResetPort() { + l := p.logger.Named("ResetPort") + l.Debug("fired") + p.rwLock.Lock() defer p.rwLock.Unlock() + l.Debug("acquired rwLock.Lock") if p.mustRead.TryLock() { + l.Debug("able to lock mustRead") p.port = 0 + return } + l.Debug("unable to lock mustRead") } // GetPort gets the current value of portManager.port without any concern for the state of its value // and therefore does not block until portManager.mustRead.Unlock() is called func (p *portManger) GetPort() int { + l := p.logger.Named("GetPort") + l.Debug("fired") + p.rwLock.RLock() defer p.rwLock.RUnlock() + l.Debug("acquired rwLock.RLock") + return p.port } // MustGetPort only returns portManager.port if portManager.mustRead is unlocked. // This presupposes that portManger.mustRead has a default state of locked and SetPort unlock portManager.mustRead func (p *portManger) MustGetPort() int { + l := p.logger.Named("MustGetPort") + l.Debug("fired") + p.mustRead.Lock() defer p.mustRead.Unlock() + l.Debug("acquired mustRead.Lock") p.rwLock.RLock() defer p.rwLock.RUnlock() + l.Debug("acquired rwLock.RLock") return p.port } diff --git a/server/server.go b/server/server.go index c000a53c9..96cdf2215 100644 --- a/server/server.go +++ b/server/server.go @@ -24,11 +24,12 @@ type Server struct { } func NewServer(cert *tls.Certificate, hostname string, afterPortChanged func(int)) Server { + logger := logutils.ZapLogger() return Server{ - logger: logutils.ZapLogger(), + logger: logger, cert: cert, hostname: hostname, - portManger: newPortManager(afterPortChanged), + portManger: newPortManager(logger, afterPortChanged), } } diff --git a/server/server_test.go b/server/server_test.go index e5b4e53d8..9a346511b 100644 --- a/server/server_test.go +++ b/server/server_test.go @@ -5,6 +5,8 @@ import ( "time" "github.com/stretchr/testify/suite" + + "github.com/status-im/status-go/logutils" ) const ( @@ -26,17 +28,18 @@ type ServerURLSuite struct { func (s *ServerURLSuite) SetupTest() { s.SetupKeyComponents(s.T()) + logger := logutils.ZapLogger() s.server = &MediaServer{Server: Server{ hostname: defaultIP.String(), - portManger: newPortManager(nil), + portManger: newPortManager(logger, nil), }} err := s.server.SetPort(1337) s.Require().NoError(err) s.serverNoPort = &MediaServer{Server: Server{ hostname: defaultIP.String(), - portManger: newPortManager(nil), + portManger: newPortManager(logger, nil), }} go func() { time.Sleep(waitTime) diff --git a/signal/events_messenger.go b/signal/events_messenger.go index 9cee35368..3278f5a39 100644 --- a/signal/events_messenger.go +++ b/signal/events_messenger.go @@ -7,11 +7,11 @@ const ( // EventMesssageDelivered triggered when we got acknowledge from datasync level, that means peer got message EventMesssageDelivered = "message.delivered" - // EventCommunityFound triggered when user requested info about some community and messenger successfully + // EventCommunityInfoFound triggered when user requested info about some community and messenger successfully // retrieved it from mailserver EventCommunityInfoFound = "community.found" - // Event Automatic Status Updates Timed out + // EventStatusUpdatesTimedOut Event Automatic Status Updates Timed out EventStatusUpdatesTimedOut = "status.updates.timedout" )