From a47c18ff5ba8ff445a27e33c03e54c02439487d1 Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Tue, 17 Apr 2018 13:27:55 -0700 Subject: [PATCH] embed: clean up initial server start logs Signed-off-by: Gyuho Lee --- embed/config.go | 102 +++++++++++++++++++++++++++----------- embed/etcd.go | 113 +++++++++++++++++++++++++++++-------------- embed/serve.go | 8 ++- etcdserver/config.go | 30 +++++++----- etcdserver/server.go | 4 +- 5 files changed, 175 insertions(+), 82 deletions(-) diff --git a/embed/config.go b/embed/config.go index 55e6a746e88..e4bc9a00d46 100644 --- a/embed/config.go +++ b/embed/config.go @@ -290,30 +290,40 @@ func NewConfig() *Config { lcurl, _ := url.Parse(DefaultListenClientURLs) acurl, _ := url.Parse(DefaultAdvertiseClientURLs) cfg := &Config{ - MaxSnapFiles: DefaultMaxSnapshots, - MaxWalFiles: DefaultMaxWALs, - Name: DefaultName, - SnapCount: etcdserver.DefaultSnapCount, - MaxTxnOps: DefaultMaxTxnOps, - MaxRequestBytes: DefaultMaxRequestBytes, + MaxSnapFiles: DefaultMaxSnapshots, + MaxWalFiles: DefaultMaxWALs, + + Name: DefaultName, + + SnapCount: etcdserver.DefaultSnapCount, + MaxTxnOps: DefaultMaxTxnOps, + MaxRequestBytes: DefaultMaxRequestBytes, + GRPCKeepAliveMinTime: DefaultGRPCKeepAliveMinTime, GRPCKeepAliveInterval: DefaultGRPCKeepAliveInterval, GRPCKeepAliveTimeout: DefaultGRPCKeepAliveTimeout, - TickMs: 100, - ElectionMs: 1000, - LPUrls: []url.URL{*lpurl}, - LCUrls: []url.URL{*lcurl}, - APUrls: []url.URL{*apurl}, - ACUrls: []url.URL{*acurl}, - ClusterState: ClusterStateFlagNew, - InitialClusterToken: "etcd-cluster", - StrictReconfigCheck: DefaultStrictReconfigCheck, - Metrics: "basic", - EnableV2: DefaultEnableV2, - CORS: map[string]struct{}{"*": {}}, - HostWhitelist: map[string]struct{}{"*": {}}, - AuthToken: "simple", - PreVote: false, // TODO: enable by default in v3.5 + + TickMs: 100, + ElectionMs: 1000, + + LPUrls: []url.URL{*lpurl}, + LCUrls: []url.URL{*lcurl}, + APUrls: []url.URL{*apurl}, + ACUrls: []url.URL{*acurl}, + + ClusterState: ClusterStateFlagNew, + InitialClusterToken: "etcd-cluster", + + StrictReconfigCheck: DefaultStrictReconfigCheck, + Metrics: "basic", + EnableV2: DefaultEnableV2, + + CORS: map[string]struct{}{"*": {}}, + HostWhitelist: map[string]struct{}{"*": {}}, + + AuthToken: "simple", + + PreVote: false, // TODO: enable by default in v3.5 loggerMu: new(sync.RWMutex), logger: nil, @@ -609,17 +619,11 @@ func (cfg *Config) Validate() error { return err } if err := checkHostURLs(cfg.APUrls); err != nil { - addrs := make([]string, len(cfg.APUrls)) - for i := range cfg.APUrls { - addrs[i] = cfg.APUrls[i].String() - } + addrs := cfg.getAPURLs() return fmt.Errorf(`--initial-advertise-peer-urls %q must be "host:port" (%v)`, strings.Join(addrs, ","), err) } if err := checkHostURLs(cfg.ACUrls); err != nil { - addrs := make([]string, len(cfg.ACUrls)) - for i := range cfg.ACUrls { - addrs[i] = cfg.ACUrls[i].String() - } + addrs := cfg.getACURLs() return fmt.Errorf(`--advertise-client-urls %q must be "host:port" (%v)`, strings.Join(addrs, ","), err) } // Check if conflicting flags are passed. @@ -870,3 +874,43 @@ func checkHostURLs(urls []url.URL) error { } return nil } + +func (cfg *Config) getAPURLs() (ss []string) { + ss = make([]string, len(cfg.APUrls)) + for i := range cfg.APUrls { + ss[i] = cfg.APUrls[i].String() + } + return ss +} + +func (cfg *Config) getLPURLs() (ss []string) { + ss = make([]string, len(cfg.LPUrls)) + for i := range cfg.LPUrls { + ss[i] = cfg.LPUrls[i].String() + } + return ss +} + +func (cfg *Config) getACURLs() (ss []string) { + ss = make([]string, len(cfg.ACUrls)) + for i := range cfg.ACUrls { + ss[i] = cfg.ACUrls[i].String() + } + return ss +} + +func (cfg *Config) getLCURLs() (ss []string) { + ss = make([]string, len(cfg.LCUrls)) + for i := range cfg.LCUrls { + ss[i] = cfg.LCUrls[i].String() + } + return ss +} + +func (cfg *Config) getMetricsURLs() (ss []string) { + ss = make([]string, len(cfg.ListenMetricsUrls)) + for i := range cfg.ListenMetricsUrls { + ss[i] = cfg.ListenMetricsUrls[i].String() + } + return ss +} diff --git a/embed/etcd.go b/embed/etcd.go index dace350f2e4..86697c58c3f 100644 --- a/embed/etcd.go +++ b/embed/etcd.go @@ -111,12 +111,26 @@ func StartEtcd(inCfg *Config) (e *Etcd, err error) { e = nil }() - if e.Peers, err = startPeerListeners(cfg); err != nil { + if e.cfg.logger != nil { + e.cfg.logger.Info( + "configuring peer listeners", + zap.Strings("listen-peer-urls", e.cfg.getLPURLs()), + ) + } + if e.Peers, err = configurePeerListeners(cfg); err != nil { return e, err } - if e.sctxs, err = startClientListeners(cfg); err != nil { + + if e.cfg.logger != nil { + e.cfg.logger.Info( + "configuring client listeners", + zap.Strings("listen-client-urls", e.cfg.getLCURLs()), + ) + } + if e.sctxs, err = configureClientListeners(cfg); err != nil { return e, err } + for _, sctx := range e.sctxs { e.Clients = append(e.Clients, sctx.l) } @@ -189,11 +203,7 @@ func StartEtcd(inCfg *Config) (e *Etcd, err error) { } sort.Strings(ss) if e.cfg.logger != nil { - e.cfg.logger.Info( - "starting with CORS", - zap.String("server-id", e.Server.ID().String()), - zap.Strings("cors", ss), - ) + e.cfg.logger.Info("configured CORS", zap.Strings("cors", ss)) } else { plog.Infof("%s starting with cors %q", e.Server.ID(), ss) } @@ -205,11 +215,7 @@ func StartEtcd(inCfg *Config) (e *Etcd, err error) { } sort.Strings(ss) if e.cfg.logger != nil { - e.cfg.logger.Info( - "starting with host whitelist", - zap.String("server-id", e.Server.ID().String()), - zap.Strings("hosts", ss), - ) + e.cfg.logger.Info("configured host whitelist", zap.Strings("hosts", ss)) } else { plog.Infof("%s starting with host whitelist %q", e.Server.ID(), ss) } @@ -240,6 +246,17 @@ func StartEtcd(inCfg *Config) (e *Etcd, err error) { return e, err } + if e.cfg.logger != nil { + e.cfg.logger.Info( + "now serving peer/client/metrics", + zap.String("local-member-id", e.Server.ID().String()), + zap.Strings("initial-advertise-peer-urls", e.cfg.getAPURLs()), + zap.Strings("listen-peer-urls", e.cfg.getLPURLs()), + zap.Strings("advertise-client-urls", e.cfg.getACURLs()), + zap.Strings("listen-client-urls", e.cfg.getLCURLs()), + zap.Strings("listen-metrics-urls", e.cfg.getMetricsURLs()), + ) + } serving = true return e, nil } @@ -336,7 +353,7 @@ func stopServers(ctx context.Context, ss *servers) { func (e *Etcd) Err() <-chan error { return e.errc } -func startPeerListeners(cfg *Config) (peers []*peerListener, err error) { +func configurePeerListeners(cfg *Config) (peers []*peerListener, err error) { if err = cfg.PeerSelfCert(); err != nil { if cfg.logger != nil { cfg.logger.Fatal("failed to get peer self-signed certs", zap.Error(err)) @@ -360,7 +377,11 @@ func startPeerListeners(cfg *Config) (peers []*peerListener, err error) { for i := range peers { if peers[i] != nil && peers[i].close != nil { if cfg.logger != nil { - cfg.logger.Info("stopping listening for peers", zap.String("address", cfg.LPUrls[i].String())) + cfg.logger.Warn( + "closing peer listener", + zap.String("address", cfg.LPUrls[i].String()), + zap.Error(err), + ) } else { plog.Info("stopping listening for peers on ", cfg.LPUrls[i].String()) } @@ -397,11 +418,6 @@ func startPeerListeners(cfg *Config) (peers []*peerListener, err error) { peers[i].close = func(context.Context) error { return peers[i].Listener.Close() } - if cfg.logger != nil { - cfg.logger.Info("listening for peers", zap.String("address", u.String())) - } else { - plog.Info("listening for peers on ", u.String()) - } } return peers, nil } @@ -417,6 +433,7 @@ func (e *Etcd) servePeers() (err error) { } for _, p := range e.Peers { + u := p.Listener.Addr().String() gs := v3rpc.Server(e.Server, peerTLScfg) m := cmux.New(p.Listener) go gs.Serve(m.Match(cmux.HTTP2())) @@ -431,7 +448,19 @@ func (e *Etcd) servePeers() (err error) { // gracefully shutdown http.Server // close open listeners, idle connections // until context cancel or time-out + if e.cfg.logger != nil { + e.cfg.logger.Info( + "stopping serving peer traffic", + zap.String("address", u), + ) + } stopServers(ctx, &servers{secure: peerTLScfg != nil, grpc: gs, http: srv}) + if e.cfg.logger != nil { + e.cfg.logger.Info( + "stopped serving peer traffic", + zap.String("address", u), + ) + } return nil } } @@ -439,13 +468,22 @@ func (e *Etcd) servePeers() (err error) { // start peer servers in a goroutine for _, pl := range e.Peers { go func(l *peerListener) { + u := l.Addr().String() + if e.cfg.logger != nil { + e.cfg.logger.Info( + "serving peer traffic", + zap.String("address", u), + ) + } else { + plog.Info("listening for peers on ", u) + } e.errHandler(l.serve()) }(pl) } return nil } -func startClientListeners(cfg *Config) (sctxs map[string]*serveCtx, err error) { +func configureClientListeners(cfg *Config) (sctxs map[string]*serveCtx, err error) { if err = cfg.ClientSelfCert(); err != nil { if cfg.logger != nil { cfg.logger.Fatal("failed to get client self-signed certs", zap.Error(err)) @@ -464,7 +502,6 @@ func startClientListeners(cfg *Config) (sctxs map[string]*serveCtx, err error) { sctxs = make(map[string]*serveCtx) for _, u := range cfg.LCUrls { sctx := newServeCtx(cfg.logger) - if u.Scheme == "http" || u.Scheme == "unix" { if !cfg.ClientTLSInfo.Empty() { if cfg.logger != nil { @@ -528,19 +565,19 @@ func startClientListeners(cfg *Config) (sctxs map[string]*serveCtx, err error) { } } - if cfg.logger != nil { - cfg.logger.Info("listening for client requests", zap.String("host", u.Host)) - } else { - plog.Info("listening for client requests on ", u.Host) - } defer func() { - if err != nil { - sctx.l.Close() - if cfg.logger != nil { - cfg.logger.Info("stopping listening for client requests", zap.String("host", u.Host)) - } else { - plog.Info("stopping listening for client requests on ", u.Host) - } + if err == nil { + return + } + sctx.l.Close() + if cfg.logger != nil { + cfg.logger.Warn( + "closing peer listener", + zap.String("address", u.Host), + zap.Error(err), + ) + } else { + plog.Info("stopping listening for client requests on ", u.Host) } }() for k := range cfg.UserHandlers { @@ -561,7 +598,10 @@ func startClientListeners(cfg *Config) (sctxs map[string]*serveCtx, err error) { func (e *Etcd) serveClients() (err error) { if !e.cfg.ClientTLSInfo.Empty() { if e.cfg.logger != nil { - e.cfg.logger.Info("starting with client TLS", zap.String("tls-info", fmt.Sprintf("%+v", e.cfg.ClientTLSInfo))) + e.cfg.logger.Info( + "starting with client TLS", + zap.String("tls-info", fmt.Sprintf("%+v", e.cfg.ClientTLSInfo)), + ) } else { plog.Infof("ClientTLS: %s", e.cfg.ClientTLSInfo) } @@ -627,7 +667,10 @@ func (e *Etcd) serveMetrics() (err error) { e.metricsListeners = append(e.metricsListeners, ml) go func(u url.URL, ln net.Listener) { if e.cfg.logger != nil { - e.cfg.logger.Info("listening for metrics", zap.String("url", u.String())) + e.cfg.logger.Info( + "serving metrics", + zap.String("address", u.String()), + ) } else { plog.Info("listening for metrics on ", u.String()) } diff --git a/embed/serve.go b/embed/serve.go index 13b900188b0..789921e491c 100644 --- a/embed/serve.go +++ b/embed/serve.go @@ -90,9 +90,7 @@ func (sctx *serveCtx) serve( logger := defaultLog.New(ioutil.Discard, "etcdhttp", 0) <-s.ReadyNotify() - if sctx.lg != nil { - sctx.lg.Info("ready to server client requests") - } else { + if sctx.lg == nil { plog.Info("ready to serve client requests") } @@ -136,7 +134,7 @@ func (sctx *serveCtx) serve( sctx.serversC <- &servers{grpc: gs, http: srvhttp} if sctx.lg != nil { sctx.lg.Info( - "serving insecure client requests; this is strongly discouraged!", + "serving client traffic insecurely; this is strongly discouraged!", zap.String("address", sctx.l.Addr().String()), ) } else { @@ -186,7 +184,7 @@ func (sctx *serveCtx) serve( sctx.serversC <- &servers{secure: true, grpc: gs, http: srv} if sctx.lg != nil { sctx.lg.Info( - "serving client requests", + "serving client traffic insecurely", zap.String("address", sctx.l.Addr().String()), ) } else { diff --git a/etcdserver/config.go b/etcdserver/config.go index b518bcd0dd6..9d9cd4047f3 100644 --- a/etcdserver/config.go +++ b/etcdserver/config.go @@ -248,20 +248,12 @@ func (c *ServerConfig) print(initial bool) { plog.Infof("initial cluster = %s", c.InitialPeerURLsMap) } } else { - caddrs := make([]string, len(c.ClientURLs)) - for i := range c.ClientURLs { - caddrs[i] = c.ClientURLs[i].String() - } - paddrs := make([]string, len(c.PeerURLs)) - for i := range c.PeerURLs { - paddrs[i] = c.PeerURLs[i].String() - } state := "new" if !c.NewCluster { state = "existing" } c.Logger.Info( - "server starting", + "server configuration", zap.String("name", c.Name), zap.String("data-dir", c.DataDir), zap.String("member-dir", c.MemberDir()), @@ -272,8 +264,8 @@ func (c *ServerConfig) print(initial bool) { zap.Int("election-tick-ms", c.ElectionTicks), zap.String("election-timeout", fmt.Sprintf("%v", time.Duration(c.ElectionTicks*int(c.TickMs))*time.Millisecond)), zap.Uint64("snapshot-count", c.SnapCount), - zap.Strings("advertise-client-urls", caddrs), - zap.Strings("initial-advertise-peer-urls", paddrs), + zap.Strings("advertise-client-urls", c.getACURLs()), + zap.Strings("initial-advertise-peer-urls", c.getAPURLs()), zap.Bool("initial", initial), zap.String("initial-cluster", c.InitialPeerURLsMap.String()), zap.String("initial-cluster-state", state), @@ -309,3 +301,19 @@ func (c *ServerConfig) bootstrapTimeout() time.Duration { } func (c *ServerConfig) backendPath() string { return filepath.Join(c.SnapDir(), "db") } + +func (c *ServerConfig) getAPURLs() (ss []string) { + ss = make([]string, len(c.PeerURLs)) + for i := range c.PeerURLs { + ss[i] = c.PeerURLs[i].String() + } + return ss +} + +func (c *ServerConfig) getACURLs() (ss []string) { + ss = make([]string, len(c.ClientURLs)) + for i := range c.ClientURLs { + ss[i] = c.ClientURLs[i].String() + } + return ss +} diff --git a/etcdserver/server.go b/etcdserver/server.go index cf1a480293e..17f9d940008 100644 --- a/etcdserver/server.go +++ b/etcdserver/server.go @@ -711,7 +711,7 @@ func (s *EtcdServer) start() { if s.ClusterVersion() != nil { if lg != nil { lg.Info( - "starting server", + "starting etcd server", zap.String("local-member-id", s.ID().String()), zap.String("local-server-version", version.Version), zap.String("cluster-id", s.Cluster().ID().String()), @@ -723,7 +723,7 @@ func (s *EtcdServer) start() { } else { if lg != nil { lg.Info( - "starting server", + "starting etcd server", zap.String("local-member-id", s.ID().String()), zap.String("local-server-version", version.Version), zap.String("cluster-version", "to_be_decided"),