From 1e953bd187809dbca826f7b640cabaea56635f71 Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Wed, 16 May 2018 14:11:08 -0700 Subject: [PATCH 1/6] pkg/logutil: error when it can't find journal socket Signed-off-by: Gyuho Lee --- pkg/logutil/zap_journald.go | 8 ++++++-- pkg/logutil/zap_journald_test.go | 8 +++++++- pkg/systemd/doc.go | 16 ++++++++++++++++ pkg/systemd/journal.go | 29 +++++++++++++++++++++++++++++ 4 files changed, 58 insertions(+), 3 deletions(-) create mode 100644 pkg/systemd/doc.go create mode 100644 pkg/systemd/journal.go diff --git a/pkg/logutil/zap_journald.go b/pkg/logutil/zap_journald.go index b0ae57f28..a157bebab 100644 --- a/pkg/logutil/zap_journald.go +++ b/pkg/logutil/zap_journald.go @@ -24,6 +24,8 @@ import ( "os" "path/filepath" + "github.com/coreos/etcd/pkg/systemd" + "github.com/coreos/go-systemd/journal" "go.uber.org/zap/zapcore" ) @@ -33,8 +35,8 @@ import ( // back to writing to the original writer. // The decode overhead is only <30µs per write. // Reference: https://github.com/coreos/pkg/blob/master/capnslog/journald_formatter.go -func NewJournaldWriter(wr io.Writer) io.Writer { - return &journaldWriter{Writer: wr} +func NewJournaldWriter(wr io.Writer) (io.Writer, error) { + return &journaldWriter{Writer: wr}, systemd.DialJournal() } type journaldWriter struct { @@ -82,6 +84,8 @@ func (w *journaldWriter) Write(p []byte) (int, error) { "SYSLOG_IDENTIFIER": filepath.Base(os.Args[0]), }) if err != nil { + // "journal" also falls back to stderr + // "fmt.Fprintln(os.Stderr, s)" return w.Writer.Write(p) } return 0, nil diff --git a/pkg/logutil/zap_journald_test.go b/pkg/logutil/zap_journald_test.go index 3e9e727b1..ddcb459eb 100644 --- a/pkg/logutil/zap_journald_test.go +++ b/pkg/logutil/zap_journald_test.go @@ -26,7 +26,13 @@ import ( func TestNewJournaldWriter(t *testing.T) { buf := bytes.NewBuffer(nil) - syncer := zapcore.AddSync(NewJournaldWriter(buf)) + jw, err := NewJournaldWriter(buf) + if err != nil { + t.Skip(err) + } + + syncer := zapcore.AddSync(jw) + cr := zapcore.NewCore( zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig()), syncer, diff --git a/pkg/systemd/doc.go b/pkg/systemd/doc.go new file mode 100644 index 000000000..30e77ce04 --- /dev/null +++ b/pkg/systemd/doc.go @@ -0,0 +1,16 @@ +// Copyright 2018 The etcd Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +// Package systemd provides utility functions for systemd. +package systemd diff --git a/pkg/systemd/journal.go b/pkg/systemd/journal.go new file mode 100644 index 000000000..b861c6942 --- /dev/null +++ b/pkg/systemd/journal.go @@ -0,0 +1,29 @@ +// Copyright 2018 The etcd Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package systemd + +import "net" + +// DialJournal returns no error if the process can dial journal socket. +// Returns an error if dial failed, whichi indicates journald is not available +// (e.g. run embedded etcd as docker daemon). +// Reference: https://github.com/coreos/go-systemd/blob/master/journal/journal.go. +func DialJournal() error { + conn, err := net.Dial("unixgram", "/run/systemd/journal/socket") + if conn != nil { + defer conn.Close() + } + return err +} From 5a61dc800861567e4d24152a788e6e3787f507f8 Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Wed, 16 May 2018 14:25:10 -0700 Subject: [PATCH 2/6] embed: error when it cannot find journal socket Signed-off-by: Gyuho Lee --- embed/config_logging.go | 6 +++++- embed/config_logging_journald_unix.go | 9 +++++++-- embed/config_logging_journald_windows.go | 4 ++-- 3 files changed, 14 insertions(+), 5 deletions(-) diff --git a/embed/config_logging.go b/embed/config_logging.go index cae94b987..4b5919c90 100644 --- a/embed/config_logging.go +++ b/embed/config_logging.go @@ -225,7 +225,11 @@ func (cfg *Config) setupLogging() error { } // use stderr as fallback - syncer := getZapWriteSyncer() + syncer, lerr := getJournalWriteSyncer() + if lerr != nil { + return lerr + } + lvl := zap.NewAtomicLevelAt(zap.InfoLevel) if cfg.Debug { lvl = zap.NewAtomicLevelAt(zap.DebugLevel) diff --git a/embed/config_logging_journald_unix.go b/embed/config_logging_journald_unix.go index c58ef9ca0..8e5e2369f 100644 --- a/embed/config_logging_journald_unix.go +++ b/embed/config_logging_journald_unix.go @@ -17,6 +17,7 @@ package embed import ( + "fmt" "os" "github.com/coreos/etcd/pkg/logutil" @@ -25,6 +26,10 @@ import ( ) // use stderr as fallback -func getZapWriteSyncer() zapcore.WriteSyncer { - return zapcore.AddSync(logutil.NewJournaldWriter(os.Stderr)) +func getJournalWriteSyncer() (zapcore.WriteSyncer, error) { + jw, err := logutil.NewJournaldWriter(os.Stderr) + if err != nil { + return nil, fmt.Errorf("can't find journald (%v)", err) + } + return zapcore.AddSync(jw), nil } diff --git a/embed/config_logging_journald_windows.go b/embed/config_logging_journald_windows.go index 4ee146d35..5b7625648 100644 --- a/embed/config_logging_journald_windows.go +++ b/embed/config_logging_journald_windows.go @@ -22,6 +22,6 @@ import ( "go.uber.org/zap/zapcore" ) -func getZapWriteSyncer() zapcore.WriteSyncer { - return zapcore.AddSync(os.Stderr) +func getJournalWriteSyncer() (zapcore.WriteSyncer, error) { + return zapcore.AddSync(os.Stderr), nil } From 3a80499da47016b9a66a3866302f3cf055bb0ce7 Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Wed, 16 May 2018 14:38:27 -0700 Subject: [PATCH 3/6] *: rename to "journal" Signed-off-by: Gyuho Lee --- ...journald_unix.go => config_logging_journal_unix.go} | 4 ++-- ...ld_windows.go => config_logging_journal_windows.go} | 0 pkg/logutil/{zap_journald.go => zap_journal.go} | 10 +++++----- .../{zap_journald_test.go => zap_journal_test.go} | 6 +++--- 4 files changed, 10 insertions(+), 10 deletions(-) rename embed/{config_logging_journald_unix.go => config_logging_journal_unix.go} (88%) rename embed/{config_logging_journald_windows.go => config_logging_journal_windows.go} (100%) rename pkg/logutil/{zap_journald.go => zap_journal.go} (89%) rename pkg/logutil/{zap_journald_test.go => zap_journal_test.go} (90%) diff --git a/embed/config_logging_journald_unix.go b/embed/config_logging_journal_unix.go similarity index 88% rename from embed/config_logging_journald_unix.go rename to embed/config_logging_journal_unix.go index 8e5e2369f..ff9ddd055 100644 --- a/embed/config_logging_journald_unix.go +++ b/embed/config_logging_journal_unix.go @@ -27,9 +27,9 @@ import ( // use stderr as fallback func getJournalWriteSyncer() (zapcore.WriteSyncer, error) { - jw, err := logutil.NewJournaldWriter(os.Stderr) + jw, err := logutil.NewJournalWriter(os.Stderr) if err != nil { - return nil, fmt.Errorf("can't find journald (%v)", err) + return nil, fmt.Errorf("can't find journal (%v)", err) } return zapcore.AddSync(jw), nil } diff --git a/embed/config_logging_journald_windows.go b/embed/config_logging_journal_windows.go similarity index 100% rename from embed/config_logging_journald_windows.go rename to embed/config_logging_journal_windows.go diff --git a/pkg/logutil/zap_journald.go b/pkg/logutil/zap_journal.go similarity index 89% rename from pkg/logutil/zap_journald.go rename to pkg/logutil/zap_journal.go index a157bebab..b1788bc83 100644 --- a/pkg/logutil/zap_journald.go +++ b/pkg/logutil/zap_journal.go @@ -30,16 +30,16 @@ import ( "go.uber.org/zap/zapcore" ) -// NewJournaldWriter wraps "io.Writer" to redirect log output +// NewJournalWriter wraps "io.Writer" to redirect log output // to the local systemd journal. If journald send fails, it fails // back to writing to the original writer. // The decode overhead is only <30µs per write. // Reference: https://github.com/coreos/pkg/blob/master/capnslog/journald_formatter.go -func NewJournaldWriter(wr io.Writer) (io.Writer, error) { - return &journaldWriter{Writer: wr}, systemd.DialJournal() +func NewJournalWriter(wr io.Writer) (io.Writer, error) { + return &journalWriter{Writer: wr}, systemd.DialJournal() } -type journaldWriter struct { +type journalWriter struct { io.Writer } @@ -50,7 +50,7 @@ type logLine struct { Caller string `json:"caller"` } -func (w *journaldWriter) Write(p []byte) (int, error) { +func (w *journalWriter) Write(p []byte) (int, error) { line := &logLine{} if err := json.NewDecoder(bytes.NewReader(p)).Decode(line); err != nil { return 0, err diff --git a/pkg/logutil/zap_journald_test.go b/pkg/logutil/zap_journal_test.go similarity index 90% rename from pkg/logutil/zap_journald_test.go rename to pkg/logutil/zap_journal_test.go index ddcb459eb..29107a5fd 100644 --- a/pkg/logutil/zap_journald_test.go +++ b/pkg/logutil/zap_journal_test.go @@ -24,9 +24,9 @@ import ( "go.uber.org/zap/zapcore" ) -func TestNewJournaldWriter(t *testing.T) { +func TestNewJournalWriter(t *testing.T) { buf := bytes.NewBuffer(nil) - jw, err := NewJournaldWriter(buf) + jw, err := NewJournalWriter(buf) if err != nil { t.Skip(err) } @@ -42,7 +42,7 @@ func TestNewJournaldWriter(t *testing.T) { lg := zap.New(cr, zap.AddCaller(), zap.ErrorOutput(syncer)) defer lg.Sync() - lg.Info("TestNewJournaldWriter") + lg.Info("TestNewJournalWriter") if buf.String() == "" { // check with "journalctl -f" t.Log("sent logs successfully to journald") From 15fcd6d599cd20d0b68eb8b75c984c3b4ce5836c Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Wed, 16 May 2018 14:47:43 -0700 Subject: [PATCH 4/6] embed: do not support "--log-outputs=default" for zap logger systemd/journal should be configured manually. Interpreting PPID 1 as systemd unit is wrong, especially when embedded etcd runs under Docker container. For such case, every single log write will error and fall back to stderr, which is inefficient. Instead, add "systemd/journal" log output option and returns error if systemd/journal socket cannot be found. "--logger=zap --log-outputs=default" will only error for v3.4, since zap logger is still experimental. v3.5 deprecates capnslog and changes "--log-outputs" default value to "--log-outputs=stderr". Signed-off-by: Gyuho Lee --- embed/config.go | 3 +++ embed/config_logging.go | 41 +++++++++++++++++------------------------ 2 files changed, 20 insertions(+), 24 deletions(-) diff --git a/embed/config.go b/embed/config.go index 64eb02995..4289b615b 100644 --- a/embed/config.go +++ b/embed/config.go @@ -59,6 +59,9 @@ const ( DefaultListenClientURLs = "http://localhost:2379" DefaultLogOutput = "default" + JournalLogOutput = "systemd/journal" + StdErrLogOutput = "stderr" + StdOutLogOutput = "stdout" // DefaultStrictReconfigCheck is the default value for "--strict-reconfig-check" flag. // It's enabled by default. diff --git a/embed/config_logging.go b/embed/config_logging.go index 4b5919c90..3cd92ce6d 100644 --- a/embed/config_logging.go +++ b/embed/config_logging.go @@ -23,7 +23,6 @@ import ( "reflect" "sort" "sync" - "syscall" "github.com/coreos/etcd/pkg/logutil" @@ -112,13 +111,13 @@ func (cfg *Config) setupLogging() error { // specify 'stdout' or 'stderr' to skip journald logging even when running under systemd output := cfg.LogOutputs[0] switch output { - case "stdout": - capnslog.SetFormatter(capnslog.NewPrettyFormatter(os.Stdout, cfg.Debug)) - case "stderr": + case StdErrLogOutput: capnslog.SetFormatter(capnslog.NewPrettyFormatter(os.Stderr, cfg.Debug)) + case StdOutLogOutput: + capnslog.SetFormatter(capnslog.NewPrettyFormatter(os.Stdout, cfg.Debug)) case DefaultLogOutput: default: - plog.Panicf(`unknown log-output %q (only supports %q, "stdout", "stderr")`, output, DefaultLogOutput) + plog.Panicf(`unknown log-output %q (only supports %q, %q, %q)`, output, DefaultLogOutput, StdErrLogOutput, StdOutLogOutput) } case "zap": @@ -147,30 +146,24 @@ func (cfg *Config) setupLogging() error { OutputPaths: make([]string, 0), ErrorOutputPaths: make([]string, 0), } + outputPaths, errOutputPaths := make(map[string]struct{}), make(map[string]struct{}) - isJournald := false + isJournal := false for _, v := range cfg.LogOutputs { switch v { case DefaultLogOutput: - if syscall.Getppid() == 1 { - // capnslog initially SetFormatter(NewDefaultFormatter(os.Stderr)) - // where "NewDefaultFormatter" returns "NewJournaldFormatter" - // specify 'stdout' or 'stderr' to override this redirects - // when syscall.Getppid() == 1 - isJournald = true - break - } + return errors.New("'--log-outputs=default' is not supported for v3.4 during zap logger migraion (use 'journal', 'stderr', 'stdout', etc.)") - outputPaths["stderr"] = struct{}{} - errOutputPaths["stderr"] = struct{}{} + case JournalLogOutput: + isJournal = true - case "stderr": - outputPaths["stderr"] = struct{}{} - errOutputPaths["stderr"] = struct{}{} + case StdErrLogOutput: + outputPaths[StdErrLogOutput] = struct{}{} + errOutputPaths[StdErrLogOutput] = struct{}{} - case "stdout": - outputPaths["stdout"] = struct{}{} - errOutputPaths["stdout"] = struct{}{} + case StdOutLogOutput: + outputPaths[StdOutLogOutput] = struct{}{} + errOutputPaths[StdOutLogOutput] = struct{}{} default: outputPaths[v] = struct{}{} @@ -178,7 +171,7 @@ func (cfg *Config) setupLogging() error { } } - if !isJournald { + if !isJournal { for v := range outputPaths { lcfg.OutputPaths = append(lcfg.OutputPaths, v) } @@ -219,7 +212,7 @@ func (cfg *Config) setupLogging() error { if len(cfg.LogOutputs) > 1 { for _, v := range cfg.LogOutputs { if v != DefaultLogOutput { - return fmt.Errorf("running as a systemd unit but other '--log-output' values (%q) are configured with 'default'; override 'default' value with something else", cfg.LogOutputs) + return fmt.Errorf("running with systemd/journal but other '--log-outputs' values (%q) are configured with 'default'; override 'default' value with something else", cfg.LogOutputs) } } } From 258d7201ebc6c01b71aa6a5e99eac3810e246e73 Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Wed, 16 May 2018 15:03:18 -0700 Subject: [PATCH 5/6] CHANGELOG: discontinue "--log-outputs=default" support for zap logger Signed-off-by: Gyuho Lee --- CHANGELOG-3.4.md | 7 +++++-- CHANGELOG-3.5.md | 9 ++++++++- 2 files changed, 13 insertions(+), 3 deletions(-) diff --git a/CHANGELOG-3.4.md b/CHANGELOG-3.4.md index 12144978d..4ebed3a85 100644 --- a/CHANGELOG-3.4.md +++ b/CHANGELOG-3.4.md @@ -171,8 +171,11 @@ See [security doc](https://github.com/coreos/etcd/blob/master/Documentation/op-g - **`etcd --logger=capnslog` will be deprecated in v3.5**. - Main motivation is to promote automated etcd monitoring, rather than looking back server logs when it starts breaking. Future development will make etcd log as few as possible, and make etcd easier to monitor with metrics and alerts. - e.g. `--logger=capnslog --log-outputs=default` is the default setting and same as previous etcd server logging format. - - e.g. `--logger=zap --log-outputs=default` will log server operations in [JSON-encoded format](https://godoc.org/go.uber.org/zap#NewProductionEncoderConfig) and writes logs to `os.Stderr`. - - e.g. If etcd parent process ID (`ppid`) is 1 (e.g. run with systemd), `--logger=zap --log-outputs=default` will [redirect server logs to local systemd journal](https://github.com/coreos/etcd/pull/9624) in [JSON-encoded format](https://godoc.org/go.uber.org/zap#NewProductionEncoderConfig). And if write to journald fails, it writes to `os.Stderr` as a fallback. + - e.g. `--logger=zap --log-outputs=default` is not supported when `--logger=zap`. + - Use `etcd --log-outputs=systemd/journal` to send logs to the local systemd journal. + - Previously, if etcd parent process ID (`ppid`) is 1 (e.g. run with systemd), `--logger=capnslog --log-outputs=default` redirects server logs to local systemd journal. And if write to journald fails, it writes to `os.Stderr` as a fallback. + - However, even with `ppid` 1, it can fail to dial systemd journal (e.g. run embedded etcd with Docker container). Then, [every single log write will fail](https://github.com/coreos/etcd/pull/9729) and fall back to `os.Stderr`, which is inefficient. + - To avoid this problem, systemd journal logging must be configured manually. - e.g. `--logger=zap --log-outputs=stderr` will log server operations in [JSON-encoded format](https://godoc.org/go.uber.org/zap#NewProductionEncoderConfig) and writes logs to `os.Stderr`. Use this to override journald log redirects. - e.g. `--logger=zap --log-outputs=stdout` will log server operations in [JSON-encoded format](https://godoc.org/go.uber.org/zap#NewProductionEncoderConfig) and writes logs to `os.Stdout` Use this to override journald log redirects. - e.g. `--logger=zap --log-outputs=a.log` will log server operations in [JSON-encoded format](https://godoc.org/go.uber.org/zap#NewProductionEncoderConfig) and writes logs to the specified file `a.log`. diff --git a/CHANGELOG-3.5.md b/CHANGELOG-3.5.md index ed9ba1557..4bc8d0bd0 100644 --- a/CHANGELOG-3.5.md +++ b/CHANGELOG-3.5.md @@ -13,7 +13,14 @@ See [code changes](https://github.com/coreos/etcd/compare/v3.4.0...v3.5.0) and [ - Deprecated [`/v3beta`](https://github.com/coreos/etcd/pull/9298). - `curl -L http://localhost:2379/v3beta/kv/put -X POST -d '{"key": "Zm9v", "value": "YmFy"}'` does work in v3.5. Use `curl -L http://localhost:2379/v3/kv/put -X POST -d '{"key": "Zm9v", "value": "YmFy"}'` instead. - **`etcd --log-output` flag has been deprecated.** Use **`etcd --log-outputs`** instead. -- **`etcd --logger=capnslog` flag has been deprecated.** Now, **`etcd --logger=zap`** is the default. +- **`etcd --logger=zap`** is now the default. +- **`etcd --logger=capnslog` flag has been deprecated.** +- **`etcd --logger=zap --log-outputs=default` flag value is not supported.**. + - Use `etcd --log-outputs=systemd/journal` to send logs to the local systemd journal. + - Previously, if etcd parent process ID (`ppid`) is 1 (e.g. run with systemd), `--logger=capnslog --log-outputs=default` redirects server logs to local systemd journal. And if write to journald fails, it writes to `os.Stderr` as a fallback. + - However, even with `ppid` 1, it can fail to dial systemd journal (e.g. run embedded etcd with Docker container). Then, [every single log write will fail](https://github.com/coreos/etcd/pull/9729) and fall back to `os.Stderr`, which is inefficient. + - To avoid this problem, systemd journal logging must be configured manually. +- **`etcd --log-outputs=stderr`** is now the default. - **`etcd --log-package-levels` flag for `capnslog` has been deprecated.** Now, **`etcd --logger=zap`** is the default. - **`[CLIENT-URL]/config/local/log` endpoint has been deprecated, as is `etcd --log-package-levels` flag.** - `curl http://127.0.0.1:2379/config/local/log -XPUT -d '{"Level":"DEBUG"}'` won't work. From 265a37f006526d044b781a79bfa699ab57465cca Mon Sep 17 00:00:00 2001 From: Gyuho Lee Date: Wed, 16 May 2018 15:04:52 -0700 Subject: [PATCH 6/6] integration: remove unnecessary blank line Signed-off-by: Gyuho Lee --- integration/embed_test.go | 1 - 1 file changed, 1 deletion(-) diff --git a/integration/embed_test.go b/integration/embed_test.go index 4df5ffbc6..6af58ea1b 100644 --- a/integration/embed_test.go +++ b/integration/embed_test.go @@ -55,7 +55,6 @@ func TestEmbedEtcd(t *testing.T) { tests[i].cfg.Logger = "zap" tests[i].cfg.LogOutputs = []string{"/dev/null"} tests[i].cfg.Debug = false - } tests[0].cfg.Durl = "abc"