This is an automated email from the ASF dual-hosted git repository.
littlecui pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/servicecomb-service-center.git
The following commit(s) were added to refs/heads/master by this push:
new 848b740 [SCB-1719] Support access log (#622)
848b740 is described below
commit 848b7407dfc6fb8e4b110a304a28f96543c73bb2
Author: humingcheng <[email protected]>
AuthorDate: Sun Jan 19 15:14:57 2020 +0800
[SCB-1719] Support access log (#622)
* [SCB-1719] Support access log
* [SCB-1719] Support access log
* Ensure thread safety and timely sync in log
---
etc/conf/app.conf | 7 ++
pkg/log/log_test.go | 5 ++
pkg/log/zap.go | 46 ++++++++++--
server/bootstrap/bootstrap.go | 2 +
server/core/config.go | 16 ++--
server/core/proto/types.go | 14 ++--
server/handler/accesslog/handler.go | 121 +++++++++++++++++++++++++++++++
server/handler/accesslog/handler_test.go | 35 +++++++++
8 files changed, 227 insertions(+), 19 deletions(-)
diff --git a/etc/conf/app.conf b/etc/conf/app.conf
index 41eb652..d40cc50 100644
--- a/etc/conf/app.conf
+++ b/etc/conf/app.conf
@@ -152,6 +152,13 @@ log_backup_count = 50
log_format = text
# whether enable record syslog
log_sys = false
+# access log format: remoteIp requestReceiveTime "method requestUri proto"
statusCode requestBodySize delay(ms)
+# example: 127.0.0.1 2006-01-02T15:04:05.000Z07:00 "GET
/v4/default/registry/microservices HTTP/1.1" 200 0 0
+# access log inherits log's rotate and backup configuration
+# whether enable access log
+# enable_access_log = true
+# access log file
+access_log_file = "./access.log"
###################################################################
# above is the global configurations
diff --git a/pkg/log/log_test.go b/pkg/log/log_test.go
index be79e9c..72eaa9c 100644
--- a/pkg/log/log_test.go
+++ b/pkg/log/log_test.go
@@ -84,6 +84,11 @@ func TestNewLogger(t *testing.T) {
l.Fatal("a", nil)
}
+func TestNewLoggerWithEmptyConfig(t *testing.T) {
+ l := NewLogger(Config{})
+ l.Info("a")
+}
+
func TestLogPanic(t *testing.T) {
defer func() {
defer func() {
diff --git a/pkg/log/zap.go b/pkg/log/zap.go
index 3040c6e..49922a2 100644
--- a/pkg/log/zap.go
+++ b/pkg/log/zap.go
@@ -37,8 +37,8 @@ const (
)
var (
- StdoutSyncer = zapcore.AddSync(os.Stdout)
- StderrSyncer = zapcore.AddSync(os.Stderr)
+ StdoutSyncer = zapcore.Lock(os.Stdout)
+ StderrSyncer = zapcore.Lock(os.Stderr)
zapLevelMap = map[string]zapcore.Level{
"DEBUG": zap.DebugLevel,
@@ -61,6 +61,9 @@ type Config struct {
// days
LogBackupAge int
CallerSkip int
+ NoTime bool // if true, not record time
+ NoLevel bool // if true, not record level
+ NoCaller bool // if true, not record caller
}
func (cfg Config) WithCallerSkip(s int) Config {
@@ -73,6 +76,21 @@ func (cfg Config) WithFile(path string) Config {
return cfg
}
+func (cfg Config) WithNoTime(b bool) Config {
+ cfg.NoTime = b
+ return cfg
+}
+
+func (cfg Config) WithNoLevel(b bool) Config {
+ cfg.NoLevel = b
+ return cfg
+}
+
+func (cfg Config) WithNoCaller(b bool) Config {
+ cfg.NoCaller = b
+ return cfg
+}
+
func Configure() Config {
return Config{
LoggerLevel: defaultLogLevel,
@@ -106,6 +124,16 @@ func toZapConfig(c Config) zapcore.Core {
EncodeCaller: zapcore.ShortCallerEncoder,
EncodeName: zapcore.FullNameEncoder,
}
+ if c.NoCaller {
+ format.CallerKey = ""
+ }
+ if c.NoLevel {
+ format.LevelKey = ""
+ levelEnabler = func(_ zapcore.Level) bool { return true }
+ }
+ if c.NoTime {
+ format.TimeKey = ""
+ }
var enc zapcore.Encoder
if c.LogFormatText {
enc = zapcore.NewConsoleEncoder(format)
@@ -209,6 +237,7 @@ func (l *Logger) Recover(r interface{}, callerSkip int) {
e.Caller.TrimmedPath(),
r,
e.Stack)
+ StderrSyncer.Sync() // sync immediately, for server may exit abnormally
if err := l.zapLogger.Core().With([]zap.Field{zap.Reflect("recover",
r)}).Write(e, nil); err != nil {
fmt.Fprintf(StderrSyncer, "%s\tERROR\t%v\n",
time.Now().Format("2006-01-02T15:04:05.000Z0700"), err)
fmt.Fprintln(StderrSyncer,
util.BytesToStringWithNoCopy(debug.Stack()))
@@ -219,14 +248,17 @@ func (l *Logger) Recover(r interface{}, callerSkip int) {
func (l *Logger) Sync() {
l.zapLogger.Sync()
+ StderrSyncer.Sync()
+ StdoutSyncer.Sync()
}
func NewLogger(cfg Config) *Logger {
- l := zap.New(toZapConfig(cfg),
- zap.ErrorOutput(StderrSyncer),
- zap.AddCaller(),
- zap.AddCallerSkip(cfg.CallerSkip),
- )
+ opts := make([]zap.Option, 1)
+ opts[0] = zap.ErrorOutput(StderrSyncer)
+ if !cfg.NoCaller {
+ opts = append(opts, zap.AddCaller(),
zap.AddCallerSkip(cfg.CallerSkip))
+ }
+ l := zap.New(toZapConfig(cfg), opts...)
return &Logger{
Config: cfg,
zapLogger: l,
diff --git a/server/bootstrap/bootstrap.go b/server/bootstrap/bootstrap.go
index dc53ccf..985bcd3 100644
--- a/server/bootstrap/bootstrap.go
+++ b/server/bootstrap/bootstrap.go
@@ -65,6 +65,7 @@ import _
"github.com/apache/servicecomb-service-center/server/metric"
import (
"github.com/apache/servicecomb-service-center/pkg/log"
+ "github.com/apache/servicecomb-service-center/server/handler/accesslog"
"github.com/apache/servicecomb-service-center/server/handler/auth"
"github.com/apache/servicecomb-service-center/server/handler/cache"
"github.com/apache/servicecomb-service-center/server/handler/context"
@@ -84,6 +85,7 @@ func init() {
interceptor.RegisterInterceptFunc(cors.Intercept)
// handle requests after routing.
+ accesslog.RegisterHandlers()
maxbody.RegisterHandlers()
metric.RegisterHandlers()
tracing.RegisterHandlers()
diff --git a/server/core/config.go b/server/core/config.go
index 00948fe..fa720a1 100644
--- a/server/core/config.go
+++ b/server/core/config.go
@@ -82,6 +82,8 @@ func newInfo() pb.ServerInformation {
if err == nil && cacheTTL < minCacheTTL {
cacheTTL = minCacheTTL
}
+ accessLogFileFromConfig :=
beego.AppConfig.DefaultString("access_log_file", "./access.log")
+ accessLogFile := util.GetEnvString("SC_ACCESS_LOG_FILE",
accessLogFileFromConfig)
return pb.ServerInformation{
Version: InitVersion,
@@ -108,12 +110,14 @@ func newInfo() pb.ServerInformation {
CompactIndexDelta:
beego.AppConfig.DefaultInt64("compact_index_delta", 100),
CompactInterval:
beego.AppConfig.String("compact_interval"),
- LogRotateSize: maxLogFileSize,
- LogBackupCount: maxLogBackupCount,
- LogFilePath: beego.AppConfig.String("logfile"),
- LogLevel: beego.AppConfig.String("loglevel"),
- LogFormat:
beego.AppConfig.DefaultString("log_format", "text"),
- LogSys: beego.AppConfig.DefaultBool("log_sys",
false),
+ LogRotateSize: maxLogFileSize,
+ LogBackupCount: maxLogBackupCount,
+ LogFilePath: beego.AppConfig.String("logfile"),
+ LogLevel: beego.AppConfig.String("loglevel"),
+ LogFormat:
beego.AppConfig.DefaultString("log_format", "text"),
+ LogSys: beego.AppConfig.DefaultBool("log_sys",
false),
+ EnableAccessLog:
beego.AppConfig.String("enable_access_log") == "true",
+ AccessLogFile: accessLogFile,
PluginsDir:
beego.AppConfig.DefaultString("plugins_dir", "./plugins"),
Plugins: util.NewJSONObject(),
diff --git a/server/core/proto/types.go b/server/core/proto/types.go
index 3acde78..429cd57 100644
--- a/server/core/proto/types.go
+++ b/server/core/proto/types.go
@@ -52,12 +52,14 @@ type ServerConfig struct {
EnablePProf bool `json:"enablePProf"`
EnableCache bool `json:"enableCache"`
- LogRotateSize int64 `json:"-"`
- LogBackupCount int64 `json:"-"`
- LogFilePath string `json:"-"`
- LogLevel string `json:"-"`
- LogFormat string `json:"-"`
- LogSys bool `json:"-"`
+ LogRotateSize int64 `json:"-"`
+ LogBackupCount int64 `json:"-"`
+ LogFilePath string `json:"-"`
+ LogLevel string `json:"-"`
+ LogFormat string `json:"-"`
+ LogSys bool `json:"-"`
+ EnableAccessLog bool `json:"-"`
+ AccessLogFile string `json:"-"`
PluginsDir string `json:"-"`
Plugins util.JSONObject `json:"plugins"`
diff --git a/server/handler/accesslog/handler.go
b/server/handler/accesslog/handler.go
new file mode 100644
index 0000000..dab3d5f
--- /dev/null
+++ b/server/handler/accesslog/handler.go
@@ -0,0 +1,121 @@
+// Licensed to the Apache Software Foundation (ASF) under one or more
+// contributor license agreements. See the NOTICE file distributed with
+// this work for additional information regarding copyright ownership.
+// The ASF licenses this file to You 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.
+
+// +build go1.9
+
+package accesslog
+
+import (
+ "fmt"
+ "net/http"
+ "os"
+ "time"
+
+ "github.com/apache/servicecomb-service-center/pkg/chain"
+ "github.com/apache/servicecomb-service-center/pkg/log"
+ "github.com/apache/servicecomb-service-center/pkg/rest"
+ "github.com/apache/servicecomb-service-center/pkg/util"
+ "github.com/apache/servicecomb-service-center/server/core"
+ svr "github.com/apache/servicecomb-service-center/server/rest"
+)
+
+// Handler implements chain.Handler
+// Handler records access log.
+// Make sure to complete the initialization before handling the request.
+type Handler struct {
+ logger *log.Logger
+ whiteListAPIs map[string]struct{} // not record access log
+}
+
+// AddWhiteListAPIs adds APIs to white list, where the APIs will be ignored
+// in access log.
+// Not safe for concurrent use.
+func (h *Handler) AddWhiteListAPIs(apis ...string) {
+ for _, api := range apis {
+ h.whiteListAPIs[api] = struct{}{}
+ }
+}
+
+// ShouldIgnoreAPI judges whether the API should be ignored in access log.
+func (h *Handler) ShouldIgnoreAPI(api string) bool {
+ _, ok := h.whiteListAPIs[api]
+ return ok
+}
+
+// Handle handles the request
+func (h *Handler) Handle(i *chain.Invocation) {
+ matchPattern := i.Context().Value(rest.CTX_MATCH_PATTERN).(string)
+ if h.ShouldIgnoreAPI(matchPattern) {
+ i.Next()
+ return
+ }
+ startTimeStr := "unknown"
+ start, ok := i.Context().Value(svr.CTX_START_TIMESTAMP).(time.Time)
+ if ok {
+ startTimeStr = start.Format("2006-01-02T15:04:05.000Z07:00")
+ }
+ r := i.Context().Value(rest.CTX_REQUEST).(*http.Request)
+ w := i.Context().Value(rest.CTX_RESPONSE).(http.ResponseWriter)
+ i.Next(chain.WithAsyncFunc(func(_ chain.Result) {
+ delayByMillisecond := "unknown"
+ if ok {
+ delayByMillisecond = fmt.Sprintf("%d",
time.Since(start)/time.Millisecond)
+ }
+ statusCode := w.Header().Get(rest.HEADER_RESPONSE_STATUS)
+ // format: remoteIp requestReceiveTime "method requestUri
proto" statusCode requestBodySize delay(ms)
+ // example: 127.0.0.1 2006-01-02T15:04:05.000Z07:00 "GET
/v4/default/registry/microservices HTTP/1.1" 200 0 0
+ h.logger.Infof("%s %s \"%s %s %s\" %s %d %s",
+ util.GetIPFromContext(i.Context()),
+ startTimeStr,
+ r.Method,
+ r.RequestURI,
+ r.Proto,
+ statusCode,
+ r.ContentLength,
+ delayByMillisecond)
+ }))
+}
+
+// NewAccessLogHandler creates a Handler
+func NewAccessLogHandler(l *log.Logger) *Handler {
+ return &Handler{
+ logger: l,
+ whiteListAPIs: make(map[string]struct{}, 0)}
+}
+
+// RegisterHandlers registers an access log handler to the handler chain
+func RegisterHandlers() {
+ if !core.ServerInfo.Config.EnableAccessLog {
+ return
+ }
+ logger := log.NewLogger(log.Config{
+ LoggerFile:
os.ExpandEnv(core.ServerInfo.Config.AccessLogFile),
+ LogFormatText: true,
+ LogRotateSize: int(core.ServerInfo.Config.LogRotateSize),
+ LogBackupCount: int(core.ServerInfo.Config.LogBackupCount),
+ NoCaller: true,
+ NoTime: true,
+ NoLevel: true,
+ })
+ h := NewAccessLogHandler(logger)
+ // no access log for heartbeat
+ h.AddWhiteListAPIs(
+
"/v4/:project/registry/microservices/:serviceId/instances/:instanceId/heartbeat",
+ "/v4/:project/registry/heartbeats",
+
"/registry/v3/microservices/:serviceId/instances/:instanceId/heartbeat",
+ "/registry/v3/heartbeats",
+ "")
+ chain.RegisterHandler(rest.ServerChainName, h)
+}
diff --git a/server/handler/accesslog/handler_test.go
b/server/handler/accesslog/handler_test.go
new file mode 100644
index 0000000..c6edcd3
--- /dev/null
+++ b/server/handler/accesslog/handler_test.go
@@ -0,0 +1,35 @@
+package accesslog_test
+
+import (
+ "context"
+ "net/http"
+ "net/http/httptest"
+ "testing"
+
+ "github.com/apache/servicecomb-service-center/pkg/chain"
+ "github.com/apache/servicecomb-service-center/pkg/log"
+ "github.com/apache/servicecomb-service-center/pkg/rest"
+ "github.com/apache/servicecomb-service-center/server/handler/accesslog"
+)
+
+func TestHandler(t *testing.T) {
+ // add white list apis, ignore
+ l := log.NewLogger(log.Config{})
+ h := accesslog.NewAccessLogHandler(l)
+ testAPI := "testAPI"
+ h.AddWhiteListAPIs(testAPI)
+ if !h.ShouldIgnoreAPI(testAPI) {
+ t.Fatalf("Should ignore API: %s", testAPI)
+ }
+
+ // handle
+ inv := &chain.Invocation{}
+ ctx := context.Background()
+ inv.Init(ctx, chain.NewChain("c", []chain.Handler{}))
+ inv.WithContext(rest.CTX_MATCH_PATTERN, "/a")
+ r, _ := http.NewRequest(http.MethodGet, "http://127.0.0.1:80/a";, nil)
+ w := httptest.NewRecorder()
+ inv.WithContext(rest.CTX_REQUEST, r)
+ inv.WithContext(rest.CTX_RESPONSE, w)
+ h.Handle(inv)
+}
