diff --git a/CHANGELOG.md b/CHANGELOG.md index 52677ffed7f..2d4c7938001 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -3,6 +3,7 @@ BUG FIXES: * core: Fixed a bug that only ran a task `shutdown_delay` if the task had a registered service [[GH-7663](https://github.com/hashicorp/nomad/issues/7663)] + * agent: Fixed a bug where http server logs did not honor json log formatting, and reduced http server logging level to Trace [[GH-7748](https://github.com/hashicorp/nomad/issues/7748)] * driver/docker: Fixed a bug where retrying failed docker creation may in rare cases trigger a panic [[GH-7749](https://github.com/hashicorp/nomad/issues/7749)] * vault: Upgrade http2 library to fix Vault API calls that fail with `http2: no cached connection was available` [[GH-7673](https://github.com/hashicorp/nomad/issues/7673)] diff --git a/command/agent/http.go b/command/agent/http.go index d2d7f1914d3..0fffaee8bb1 100644 --- a/command/agent/http.go +++ b/command/agent/http.go @@ -146,6 +146,7 @@ func NewHTTPServer(agent *Agent, config *Config) (*HTTPServer, error) { Addr: srv.Addr, Handler: gzip(mux), ConnState: makeConnState(config.TLSConfig.EnableHTTP, handshakeTimeout, maxConns), + ErrorLog: newHTTPServerLogger(srv.logger), } go func() { diff --git a/command/agent/http_stdlog.go b/command/agent/http_stdlog.go new file mode 100644 index 00000000000..a960bb655ab --- /dev/null +++ b/command/agent/http_stdlog.go @@ -0,0 +1,33 @@ +package agent + +import ( + "bytes" + "log" + + hclog "github.com/hashicorp/go-hclog" +) + +func newHTTPServerLogger(logger hclog.Logger) *log.Logger { + return log.New(&httpServerLoggerAdapter{logger}, "", 0) +} + +// a logger adapter that forwards http server logs as a Trace level +// hclog log entries. Logs related to panics are forwarded with Error level. +// +// HTTP server logs are typically spurious as they represent HTTP +// client errors (e.g. TLS handshake failures). +type httpServerLoggerAdapter struct { + logger hclog.Logger +} + +func (l *httpServerLoggerAdapter) Write(data []byte) (int, error) { + if bytes.Contains(data, []byte("panic")) { + str := string(bytes.TrimRight(data, " \t\n")) + l.logger.Error(str) + } else if l.logger.IsTrace() { + str := string(bytes.TrimRight(data, " \t\n")) + l.logger.Trace(str) + } + + return len(data), nil +} diff --git a/command/agent/http_stdlog_test.go b/command/agent/http_stdlog_test.go new file mode 100644 index 00000000000..523086b2218 --- /dev/null +++ b/command/agent/http_stdlog_test.go @@ -0,0 +1,48 @@ +package agent + +import ( + "bytes" + "testing" + + "github.com/hashicorp/go-hclog" + "github.com/stretchr/testify/require" +) + +func TestHttpServerLoggerFilters_Level_Info(t *testing.T) { + var buf bytes.Buffer + hclogger := hclog.New(&hclog.LoggerOptions{ + Name: "testlog", + Output: &buf, + Level: hclog.Info, + }) + + stdlogger := newHTTPServerLogger(hclogger) + + // spurious logging would be filtered out + stdlogger.Printf("spurious logging: %v", "arg") + require.Empty(t, buf.String()) + + // panics are included + stdlogger.Printf("panic while processing: %v", "endpoint") + require.Contains(t, buf.String(), "[ERROR] testlog: panic while processing: endpoint") + +} + +func TestHttpServerLoggerFilters_Level_Trace(t *testing.T) { + var buf bytes.Buffer + hclogger := hclog.New(&hclog.LoggerOptions{ + Name: "testlog", + Output: &buf, + Level: hclog.Trace, + }) + + stdlogger := newHTTPServerLogger(hclogger) + + // spurious logging will be included as Trace level + stdlogger.Printf("spurious logging: %v", "arg") + require.Contains(t, buf.String(), "[TRACE] testlog: spurious logging: arg") + + stdlogger.Printf("panic while processing: %v", "endpoint") + require.Contains(t, buf.String(), "[ERROR] testlog: panic while processing: endpoint") + +}