From 12e6b22abe7f509654f99ba6a51b1aebd2593626 Mon Sep 17 00:00:00 2001 From: Alan Bernstein Date: Fri, 23 Jun 2017 17:27:57 -0500 Subject: [PATCH 1/9] WIP replace fmt prints with logger prints and Stderr with LogOutput --- cmd/server.go | 20 +++++++++++++++++--- fragment.go | 2 +- gossip/gossip.go | 5 ++--- holder.go | 2 +- server/server.go | 14 ++++++++++---- 5 files changed, 31 insertions(+), 12 deletions(-) diff --git a/cmd/server.go b/cmd/server.go index 3e43869c5..9ef9aa1a8 100644 --- a/cmd/server.go +++ b/cmd/server.go @@ -17,6 +17,7 @@ package cmd import ( "fmt" "io" + "log" "os" "os/signal" "runtime/pprof" @@ -44,7 +45,20 @@ It will load existing data from the configured directory, and start listening client connections on the configured port.`, RunE: func(cmd *cobra.Command, args []string) error { - fmt.Fprintf(Server.Stderr, "Pilosa %s, build time %s\n", pilosa.Version, pilosa.BuildTime) + // TODO this code is duplicated from server/server.go:Server.Run() because it hasnt run yet + var logOutput io.Writer + if Server.Config.LogPath == "" { + logOutput = stderr + } else { + var err error + logOutput, err = os.OpenFile(Server.Config.LogPath, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0600) + if err != nil { + return err + } + } + logger := log.New(logOutput, "", log.LstdFlags) + logger.Printf("Pilosa %s, build time %s\n", pilosa.Version, pilosa.BuildTime) + // fmt.Fprintf(Server.Stderr, "Pilosa %s, build time %s\n", pilosa.Version, pilosa.BuildTime) // Start CPU profiling. if Server.CPUProfile != "" { @@ -73,7 +87,7 @@ on the configured port.`, signal.Notify(c, os.Interrupt) select { case sig := <-c: - fmt.Fprintf(Server.Stderr, "Received %s; gracefully shutting down...\n", sig.String()) + logger.Printf("Received %s; gracefully shutting down...\n", sig.String()) // Second signal causes a hard shutdown. go func() { <-c; os.Exit(1) }() @@ -82,7 +96,7 @@ on the configured port.`, return err } case <-Server.Done: - fmt.Fprintf(Server.Stderr, "Server closed externally") + logger.Printf("Server closed externally") } return nil }, diff --git a/fragment.go b/fragment.go index 4758f18e8..278a23bcf 100644 --- a/fragment.go +++ b/fragment.go @@ -265,7 +265,7 @@ func (f *Fragment) openCache() error { // Unmarshal cache data. var pb internal.Cache if err := proto.Unmarshal(buf, &pb); err != nil { - log.Printf("error unmarshaling cache data, skipping: path=%s, err=%s", path, err) + f.logger().Printf("error unmarshaling cache data, skipping: path=%s, err=%s", path, err) return nil } diff --git a/gossip/gossip.go b/gossip/gossip.go index 1b15522a7..c8d9a616d 100644 --- a/gossip/gossip.go +++ b/gossip/gossip.go @@ -18,7 +18,6 @@ import ( "fmt" "io" "log" - "os" "golang.org/x/sync/errgroup" @@ -98,9 +97,9 @@ type gossipConfig struct { } // NewGossipNodeSet returns a new instance of GossipNodeSet. -func NewGossipNodeSet(name string, gossipHost string, gossipPort int, gossipSeed string, sh pilosa.StatusHandler) *GossipNodeSet { +func NewGossipNodeSet(name string, gossipHost string, gossipPort int, gossipSeed string, sh pilosa.StatusHandler, logOutput io.Writer) *GossipNodeSet { g := &GossipNodeSet{ - LogOutput: os.Stderr, + LogOutput: logOutput, } //TODO: pull memberlist config from pilosa.cfg file diff --git a/holder.go b/holder.go index 59fef1560..2fdb58e97 100644 --- a/holder.go +++ b/holder.go @@ -92,7 +92,7 @@ func (h *Holder) Open() error { continue } - h.logger().Printf("opening index: %s", filepath.Base(fi.Name())) + h.logger().Printf("opening index: %s", filepath.Base(fi.Name())) // TODO h.LogOutput not set until server.go:Server.Open() index, err := h.newIndex(h.IndexPath(filepath.Base(fi.Name())), filepath.Base(fi.Name())) if err == ErrName { diff --git a/server/server.go b/server/server.go index 7738f513c..dfa5b6e61 100644 --- a/server/server.go +++ b/server/server.go @@ -22,6 +22,7 @@ import ( "errors" "fmt" "io" + "log" "math/rand" "net" "os" @@ -100,7 +101,10 @@ func (m *Command) Run(args ...string) (err error) { if err = m.Server.Open(); err != nil { return fmt.Errorf("server.Open: %v", err) } - fmt.Fprintf(m.Stderr, "Listening as http://%s\n", m.Server.Host) + + logger := log.New(m.Server.LogOutput, "", log.LstdFlags) // TODO make this a function? + + logger.Printf("Listening as http://%s\n", m.Server.Host) return nil } @@ -132,8 +136,10 @@ func (m *Command) SetupServer() error { m.Server.LogOutput = logFile } + logger := log.New(m.Server.LogOutput, "", log.LstdFlags) + // Configure holder. - fmt.Fprintf(m.Stderr, "Using data from: %s\n", m.Config.DataDir) + logger.Printf("Using data from: %s\n", m.Config.DataDir) m.Server.Holder.Path = m.Config.DataDir m.Server.MetricInterval = time.Duration(m.Config.Metric.PollingInterval) m.Server.Holder.Stats, err = NewStatsClient(m.Config.Metric.Service, m.Config.Metric.Host) @@ -160,7 +166,7 @@ func (m *Command) SetupServer() error { switch m.Config.Cluster.Type { case "http": m.Server.Broadcaster = httpbroadcast.NewHTTPBroadcaster(m.Server, internalPortStr) - m.Server.BroadcastReceiver = httpbroadcast.NewHTTPBroadcastReceiver(internalPortStr, m.Stderr) + m.Server.BroadcastReceiver = httpbroadcast.NewHTTPBroadcastReceiver(internalPortStr, m.Server.LogOutput) m.Server.Cluster.NodeSet = httpbroadcast.NewHTTPNodeSet() err := m.Server.Cluster.NodeSet.(*httpbroadcast.HTTPNodeSet).Join(m.Server.Cluster.Nodes) if err != nil { @@ -180,7 +186,7 @@ func (m *Command) SetupServer() error { if err != nil { gossipHost = m.Config.Host } - gossipNodeSet := gossip.NewGossipNodeSet(m.Config.Host, gossipHost, gossipPort, gossipSeed, m.Server) + gossipNodeSet := gossip.NewGossipNodeSet(m.Config.Host, gossipHost, gossipPort, gossipSeed, m.Server, m.Server.LogOutput) m.Server.Cluster.NodeSet = gossipNodeSet m.Server.Broadcaster = gossipNodeSet m.Server.BroadcastReceiver = gossipNodeSet From 8c2d6e92c29f9e0e381546db39c99a7f30d1d344 Mon Sep 17 00:00:00 2001 From: Alan Bernstein Date: Fri, 23 Jun 2017 18:02:44 -0500 Subject: [PATCH 2/9] WIP Export Server.logger for use in server/server.go --- server.go | 14 +++++++------- server/server.go | 9 ++------- 2 files changed, 9 insertions(+), 14 deletions(-) diff --git a/server.go b/server.go index 37fadedd5..6154ed3e1 100644 --- a/server.go +++ b/server.go @@ -197,14 +197,14 @@ func (s *Server) Addr() net.Addr { return s.ln.Addr() } -func (s *Server) logger() *log.Logger { return log.New(s.LogOutput, "", log.LstdFlags) } +func (s *Server) Logger() *log.Logger { return log.New(s.LogOutput, "", log.LstdFlags) } func (s *Server) monitorAntiEntropy() { t := time.Now() ticker := time.NewTicker(s.AntiEntropyInterval) defer ticker.Stop() - s.logger().Printf("holder sync monitor initializing (%s interval)", s.AntiEntropyInterval) + s.Logger().Printf("holder sync monitor initializing (%s interval)", s.AntiEntropyInterval) for { // Wait for tick or a close. @@ -215,7 +215,7 @@ func (s *Server) monitorAntiEntropy() { s.Holder.Stats.Count("AntiEntropy", 1, 1.0) } - s.logger().Printf("holder sync beginning") + s.Logger().Printf("holder sync beginning") // Initialize syncer with local holder and remote client. var syncer HolderSyncer @@ -226,12 +226,12 @@ func (s *Server) monitorAntiEntropy() { // Sync holders. if err := syncer.SyncHolder(); err != nil { - s.logger().Printf("holder sync error: err=%s", err) + s.Logger().Printf("holder sync error: err=%s", err) continue } // Record successful sync in log. - s.logger().Printf("holder sync complete") + s.Logger().Printf("holder sync complete") } dif := time.Since(t) s.Holder.Stats.Histogram("AntiEntropyDuration", float64(dif), 1.0) @@ -267,7 +267,7 @@ func (s *Server) monitorMaxSlices() { localIndex.SetRemoteMaxSlice(newmax) } } else { - s.logger().Printf("Local Index not found: %s", index) + s.Logger().Printf("Local Index not found: %s", index) } } } @@ -472,7 +472,7 @@ func (s *Server) monitorRuntime() { gcn := gcnotifier.New() defer gcn.Close() - s.logger().Printf("runtime stats initializing (%s interval)", s.MetricInterval) + s.Logger().Printf("runtime stats initializing (%s interval)", s.MetricInterval) for { // Wait for tick or a close. diff --git a/server/server.go b/server/server.go index dfa5b6e61..51bee64b2 100644 --- a/server/server.go +++ b/server/server.go @@ -22,7 +22,6 @@ import ( "errors" "fmt" "io" - "log" "math/rand" "net" "os" @@ -102,9 +101,7 @@ func (m *Command) Run(args ...string) (err error) { return fmt.Errorf("server.Open: %v", err) } - logger := log.New(m.Server.LogOutput, "", log.LstdFlags) // TODO make this a function? - - logger.Printf("Listening as http://%s\n", m.Server.Host) + m.Server.Logger().Printf("Listening as http://%s\n", m.Server.Host) return nil } @@ -136,10 +133,8 @@ func (m *Command) SetupServer() error { m.Server.LogOutput = logFile } - logger := log.New(m.Server.LogOutput, "", log.LstdFlags) - // Configure holder. - logger.Printf("Using data from: %s\n", m.Config.DataDir) + m.Server.Logger().Printf("Using data from: %s\n", m.Config.DataDir) m.Server.Holder.Path = m.Config.DataDir m.Server.MetricInterval = time.Duration(m.Config.Metric.PollingInterval) m.Server.Holder.Stats, err = NewStatsClient(m.Config.Metric.Service, m.Config.Metric.Host) From 2fe21231fc31e119171367de585276516edc225d Mon Sep 17 00:00:00 2001 From: Alan Bernstein Date: Fri, 23 Jun 2017 18:03:28 -0500 Subject: [PATCH 3/9] Deduplicate logfile opening code --- server/server.go | 25 +++++++++++++++++-------- 1 file changed, 17 insertions(+), 8 deletions(-) diff --git a/server/server.go b/server/server.go index 51bee64b2..88f4c4f5d 100644 --- a/server/server.go +++ b/server/server.go @@ -123,14 +123,9 @@ func (m *Command) SetupServer() error { m.Server.Cluster = cluster // Setup logging output. - if m.Config.LogPath == "" { - m.Server.LogOutput = m.Stderr - } else { - logFile, err := os.OpenFile(m.Config.LogPath, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0600) - if err != nil { - return err - } - m.Server.LogOutput = logFile + m.Server.LogOutput, err = GetLogWriter(m.Config.LogPath, m.Stderr) + if err != nil { + return err } // Configure holder. @@ -203,6 +198,20 @@ func (m *Command) SetupServer() error { return nil } +// GetLogWriter opens a file for logging, or a default io.Writer (such as stderr) for an empty path. +func GetLogWriter(path string, defaultWriter io.Writer) (io.Writer, error) { + // This is split out so it can be used in NewServeCmd as well as SetupServer + if path == "" { + return defaultWriter, nil + } else { + logFile, err := os.OpenFile(path, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0600) + if err != nil { + return nil, err + } + return logFile, nil + } +} + func normalizeHost(host string) (string, error) { if !strings.Contains(host, ":") { host = host + ":" From b9e853dbdbdcdafe95403f85654c25f138c8f48c Mon Sep 17 00:00:00 2001 From: Alan Bernstein Date: Fri, 23 Jun 2017 18:08:30 -0500 Subject: [PATCH 4/9] Deduplicate logfile opening code --- cmd/server.go | 14 +++----------- 1 file changed, 3 insertions(+), 11 deletions(-) diff --git a/cmd/server.go b/cmd/server.go index 9ef9aa1a8..2cd2aa5a1 100644 --- a/cmd/server.go +++ b/cmd/server.go @@ -45,20 +45,12 @@ It will load existing data from the configured directory, and start listening client connections on the configured port.`, RunE: func(cmd *cobra.Command, args []string) error { - // TODO this code is duplicated from server/server.go:Server.Run() because it hasnt run yet - var logOutput io.Writer - if Server.Config.LogPath == "" { - logOutput = stderr - } else { - var err error - logOutput, err = os.OpenFile(Server.Config.LogPath, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0600) - if err != nil { - return err - } + logOutput, err := server.GetLogWriter(Server.Config.LogPath, stderr) + if err != nil { + return err } logger := log.New(logOutput, "", log.LstdFlags) logger.Printf("Pilosa %s, build time %s\n", pilosa.Version, pilosa.BuildTime) - // fmt.Fprintf(Server.Stderr, "Pilosa %s, build time %s\n", pilosa.Version, pilosa.BuildTime) // Start CPU profiling. if Server.CPUProfile != "" { From 855f224778c306d361e49df5b215aa84c6019ea2 Mon Sep 17 00:00:00 2001 From: Alan Bernstein Date: Fri, 23 Jun 2017 18:14:59 -0500 Subject: [PATCH 5/9] Pass logOutput to Holder.Open --- holder.go | 4 +++- server.go | 3 +-- 2 files changed, 4 insertions(+), 3 deletions(-) diff --git a/holder.go b/holder.go index 2fdb58e97..854d778ef 100644 --- a/holder.go +++ b/holder.go @@ -70,7 +70,7 @@ func NewHolder() *Holder { } // Open initializes the root data directory for the holder. -func (h *Holder) Open() error { +func (h *Holder) Open(logOutput io.Writer) error { if err := os.MkdirAll(h.Path, 0777); err != nil { return err } @@ -87,6 +87,8 @@ func (h *Holder) Open() error { return err } + h.LogOutput = logOutput + for _, fi := range fis { if !fi.IsDir() { continue diff --git a/server.go b/server.go index 6154ed3e1..265a400f5 100644 --- a/server.go +++ b/server.go @@ -129,7 +129,7 @@ func (s *Server) Open() error { } // Open holder. - if err := s.Holder.Open(); err != nil { + if err := s.Holder.Open(s.LogOutput); err != nil { return fmt.Errorf("opening Holder: %v", err) } @@ -159,7 +159,6 @@ func (s *Server) Open() error { // Initialize Holder. s.Holder.Broadcaster = s.Broadcaster - s.Holder.LogOutput = s.LogOutput // Serve HTTP. go func() { http.Serve(ln, s.Handler) }() From e1f44d4e319c2f1d2b267aa85aaff523ef2f1394 Mon Sep 17 00:00:00 2001 From: Alan Bernstein Date: Mon, 26 Jun 2017 11:23:37 -0500 Subject: [PATCH 6/9] Update tests --- ctl/backup_test.go | 3 ++- holder_test.go | 4 ++-- 2 files changed, 4 insertions(+), 3 deletions(-) diff --git a/ctl/backup_test.go b/ctl/backup_test.go index 512093a20..936576704 100644 --- a/ctl/backup_test.go +++ b/ctl/backup_test.go @@ -23,6 +23,7 @@ import ( "io/ioutil" "net/http/httptest" "net/url" + "os" "testing" ) @@ -190,7 +191,7 @@ func NewHolder() *Holder { // MustOpenHolder creates and opens a holder at a temporary path. Panic on error. func MustOpenHolder() *Holder { h := NewHolder() - if err := h.Open(); err != nil { + if err := h.Open(os.Stderr); err != nil { panic(err) } return h diff --git a/holder_test.go b/holder_test.go index b6864ffc9..78a9219b3 100644 --- a/holder_test.go +++ b/holder_test.go @@ -417,7 +417,7 @@ func NewHolder() *Holder { // MustOpenHolder creates and opens a holder at a temporary path. Panic on error. func MustOpenHolder() *Holder { h := NewHolder() - if err := h.Open(); err != nil { + if err := h.Open(&h.LogOutput); err != nil { panic(err) } return h @@ -439,7 +439,7 @@ func (h *Holder) Reopen() error { h.Holder = pilosa.NewHolder() h.Holder.Path = path h.Holder.LogOutput = logOutput - if err := h.Holder.Open(); err != nil { + if err := h.Holder.Open(&h.LogOutput); err != nil { return err } From d96a121347ca9ff714feda4453aeb9ad138a2c13 Mon Sep 17 00:00:00 2001 From: Alan Bernstein Date: Tue, 27 Jun 2017 09:52:40 -0500 Subject: [PATCH 7/9] Simplify function arguments --- gossip/gossip.go | 6 +++--- server/server.go | 2 +- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/gossip/gossip.go b/gossip/gossip.go index c8d9a616d..92ec94c97 100644 --- a/gossip/gossip.go +++ b/gossip/gossip.go @@ -97,9 +97,9 @@ type gossipConfig struct { } // NewGossipNodeSet returns a new instance of GossipNodeSet. -func NewGossipNodeSet(name string, gossipHost string, gossipPort int, gossipSeed string, sh pilosa.StatusHandler, logOutput io.Writer) *GossipNodeSet { +func NewGossipNodeSet(name string, gossipHost string, gossipPort int, gossipSeed string, server *pilosa.Server) *GossipNodeSet { g := &GossipNodeSet{ - LogOutput: logOutput, + LogOutput: server.LogOutput, } //TODO: pull memberlist config from pilosa.cfg file @@ -114,7 +114,7 @@ func NewGossipNodeSet(name string, gossipHost string, gossipPort int, gossipSeed g.config.memberlistConfig.AdvertisePort = gossipPort g.config.memberlistConfig.Delegate = g - g.statusHandler = sh + g.statusHandler = server return g } diff --git a/server/server.go b/server/server.go index 88f4c4f5d..f66b88870 100644 --- a/server/server.go +++ b/server/server.go @@ -176,7 +176,7 @@ func (m *Command) SetupServer() error { if err != nil { gossipHost = m.Config.Host } - gossipNodeSet := gossip.NewGossipNodeSet(m.Config.Host, gossipHost, gossipPort, gossipSeed, m.Server, m.Server.LogOutput) + gossipNodeSet := gossip.NewGossipNodeSet(m.Config.Host, gossipHost, gossipPort, gossipSeed, m.Server) m.Server.Cluster.NodeSet = gossipNodeSet m.Server.Broadcaster = gossipNodeSet m.Server.BroadcastReceiver = gossipNodeSet From 271dd5a63b07f8902018c7984abd2669f6db8b1c Mon Sep 17 00:00:00 2001 From: Alan Bernstein Date: Tue, 27 Jun 2017 21:43:26 -0500 Subject: [PATCH 8/9] Simplify holder logOutput --- ctl/backup_test.go | 3 +-- holder.go | 4 +--- holder_test.go | 4 ++-- server.go | 3 ++- 4 files changed, 6 insertions(+), 8 deletions(-) diff --git a/ctl/backup_test.go b/ctl/backup_test.go index 936576704..512093a20 100644 --- a/ctl/backup_test.go +++ b/ctl/backup_test.go @@ -23,7 +23,6 @@ import ( "io/ioutil" "net/http/httptest" "net/url" - "os" "testing" ) @@ -191,7 +190,7 @@ func NewHolder() *Holder { // MustOpenHolder creates and opens a holder at a temporary path. Panic on error. func MustOpenHolder() *Holder { h := NewHolder() - if err := h.Open(os.Stderr); err != nil { + if err := h.Open(); err != nil { panic(err) } return h diff --git a/holder.go b/holder.go index 854d778ef..2fdb58e97 100644 --- a/holder.go +++ b/holder.go @@ -70,7 +70,7 @@ func NewHolder() *Holder { } // Open initializes the root data directory for the holder. -func (h *Holder) Open(logOutput io.Writer) error { +func (h *Holder) Open() error { if err := os.MkdirAll(h.Path, 0777); err != nil { return err } @@ -87,8 +87,6 @@ func (h *Holder) Open(logOutput io.Writer) error { return err } - h.LogOutput = logOutput - for _, fi := range fis { if !fi.IsDir() { continue diff --git a/holder_test.go b/holder_test.go index 78a9219b3..b6864ffc9 100644 --- a/holder_test.go +++ b/holder_test.go @@ -417,7 +417,7 @@ func NewHolder() *Holder { // MustOpenHolder creates and opens a holder at a temporary path. Panic on error. func MustOpenHolder() *Holder { h := NewHolder() - if err := h.Open(&h.LogOutput); err != nil { + if err := h.Open(); err != nil { panic(err) } return h @@ -439,7 +439,7 @@ func (h *Holder) Reopen() error { h.Holder = pilosa.NewHolder() h.Holder.Path = path h.Holder.LogOutput = logOutput - if err := h.Holder.Open(&h.LogOutput); err != nil { + if err := h.Holder.Open(); err != nil { return err } diff --git a/server.go b/server.go index 265a400f5..1f09119e1 100644 --- a/server.go +++ b/server.go @@ -129,7 +129,8 @@ func (s *Server) Open() error { } // Open holder. - if err := s.Holder.Open(s.LogOutput); err != nil { + s.Holder.LogOutput = s.LogOutput + if err := s.Holder.Open(); err != nil { return fmt.Errorf("opening Holder: %v", err) } From 374dfd1fa048a73bd679e4e8076cbc369fb1239a Mon Sep 17 00:00:00 2001 From: Alan Bernstein Date: Tue, 27 Jun 2017 21:44:17 -0500 Subject: [PATCH 9/9] Remove TODO comment --- holder.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/holder.go b/holder.go index 2fdb58e97..59fef1560 100644 --- a/holder.go +++ b/holder.go @@ -92,7 +92,7 @@ func (h *Holder) Open() error { continue } - h.logger().Printf("opening index: %s", filepath.Base(fi.Name())) // TODO h.LogOutput not set until server.go:Server.Open() + h.logger().Printf("opening index: %s", filepath.Base(fi.Name())) index, err := h.newIndex(h.IndexPath(filepath.Base(fi.Name())), filepath.Base(fi.Name())) if err == ErrName {