diff --git a/assets/templates/middleware/access_log b/assets/templates/middleware/access_log deleted file mode 100755 index 86b4fe25ef6247f78dd491578f5b6bf05fa8e992..0000000000000000000000000000000000000000 --- a/assets/templates/middleware/access_log +++ /dev/null @@ -1,65 +0,0 @@ -import ( - "fmt" - "time" - "context" - - "go.uber.org/zap" -) - -{{ $funcName := (or .Vars.FuncName ("LoggingMiddleware")) }} -{{ $decorator := (or .Vars.DecoratorName ("loggingMiddleware")) }} - -// {{$decorator}} implements {{.Interface.Type}} that is instrumented with logging -type {{$decorator}} struct { - logger *zap.Logger - next {{.Interface.Type}} -} - -// {{$funcName}} instruments an implementation of the {{.Interface.Type}} with simple logging -func {{$funcName}}(logger *zap.Logger) Middleware { - return func(next {{.Interface.Type}}) {{.Interface.Type}} { - return &{{$decorator}}{ - next: next, - logger: logger, - } - } -} - -{{range $method := .Interface.Methods}} - func (m *{{$decorator}}) {{$method.Declaration}} { - begin := time.Now() - var fields []zapcore.Field - {{- if $method.HasParams}} - for k, v := range {{$method.ParamsMap}} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k,v)) - } - {{end}} - - m.logger.Debug("{{$method.Name}}.Request",fields...) - - {{ $method.ResultsNames }} = m.next.{{ $method.Call }} - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), - } - - {{ if $method.HasResults}} - for k, v := range {{$method.ResultsMap}} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k,v)) - } - {{end}} - - m.logger.Debug("{{$method.Name}}.Response", fields...) - - return {{ $method.ResultsNames }} - } -{{end}} diff --git a/assets/templates/middleware/access_log.tmpl b/assets/templates/middleware/access_log.tmpl new file mode 100755 index 0000000000000000000000000000000000000000..9f9899b835a1ec46652da008035f3a8931dc472d --- /dev/null +++ b/assets/templates/middleware/access_log.tmpl @@ -0,0 +1,58 @@ +import ( + "fmt" + "time" + "context" + + "go.uber.org/zap" +) + +{{ $funcName := (or .Vars.FuncName ("AccessLoggingMiddleware")) }} +{{ $decorator := (or .Vars.DecoratorName ("accessLoggingMiddleware")) }} +{{ $objectName := (trimSuffix "s" (split "." .Interface.Type)._1) }} + +// {{$decorator}} implements {{.Interface.Type}} that is instrumented with logging +type {{$decorator}} struct { + logger *zap.Logger + next {{.Interface.Type}} +} + +// {{$funcName}} instruments an implementation of the {{.Interface.Type}} with simple logging +func {{$funcName}}(logger *zap.Logger) Middleware { + return func(next {{.Interface.Type}}) {{.Interface.Type}} { + return &{{$decorator}}{ + next: next, + logger: logger, + } + } +} + +{{range $method := .Interface.Methods}} + func (m *{{$decorator}}) {{$method.Declaration}} { + begin := time.Now() + + m.logger.Debug("{{$method.Name}}.Request", + {{- range $param := $method.Params -}} + {{- if (eq $param.Name "ctx") }} + zap.Reflect("principal", auth.GetPrincipal(ctx)), + {{- else }} + zap.Reflect("{{$param.Name}}", {{$param.Name}}), + {{- end -}} + {{ end }} + ) + + {{ $method.ResultsNames }} = m.next.{{ $method.Call }} + + m.logger.Debug("{{$method.Name}}.Response", + zap.Duration("time", time.Since(begin)), + {{- range $param := $method.Results -}} + {{- if (eq $param.Name "err") }} + zap.Error(err), + {{- else }} + zap.Reflect("{{$param.Name}}", {{$param.Name}}), + {{- end -}} + {{ end }} + ) + + return {{ $method.ResultsNames }} + } +{{end}} diff --git a/assets/templates/middleware/info_log.tmpl b/assets/templates/middleware/info_log.tmpl deleted file mode 100644 index 4d431885bcc8b99c2461a593f1f42dc3d2c7aec6..0000000000000000000000000000000000000000 --- a/assets/templates/middleware/info_log.tmpl +++ /dev/null @@ -1,78 +0,0 @@ -import ( - "fmt" - "time" - "context" - - logzap "git.perx.ru/perxis/perxis-go/pkg/log/zap" - "go.uber.org/zap" - "go.uber.org/zap/zapcore" -) - -{{ $funcName := (or .Vars.FuncName ("LogMiddleware")) }} -{{ $decorator := (or .Vars.DecoratorName ("logMiddleware")) }} -{{ $packageName := (split "." .Interface.Type)._0 }} -{{ $serviceName := (split "." .Interface.Type)._1 }} -{{ $objectName := (trimSuffix "s" (split "." .Interface.Type)._1) }} -{{ $writeMethods := list "Archive" "Create" "Delete" "Publish" "Unarchive" "Undelete" "Unpublish" "Update" }} - -type {{ $decorator }} struct { - logger *zap.Logger - next {{ .Interface.Type }} -} - -func {{ $funcName }} (logger *zap.Logger) Middleware { - return func(next {{ .Interface.Type }}) {{ .Interface.Type }} { - return &{{ $decorator }}{ - next: next, - logger: logger.With(logzap.Component("{{ $serviceName }}")), - } - } -} - -{{ range $method := .Interface.Methods }} - func (m *{{ $decorator }}) {{ $method.Declaration }} { - {{- if has $method.Name $writeMethods }} - {{ $method.ResultsNames }} = m.next.{{ $method.Call }} - - {{ $inputObject := "" }} - {{ $outputObject := "" }} - - {{ if or (gt (len $method.Results) 1) (not $method.ReturnsError) }} - {{ $outputObject = (first $method.Results).Name }} - {{ end }} - - {{ if $method.AcceptsContext }} - {{ $inputObject = (first (rest $method.Params)).Name }} - {{ else if not $method.ReturnsError }} - {{ $inputObject = (first $method.Params).Name }} - {{ end }} - - fields := []zapcore.Field{ - logzap.Event({{ $packageName }}.Event{{ $method.Name }}{{ $objectName }}), - logzap.CallerFromContext(ctx), - {{ if not $outputObject }} logzap.Object({{ $inputObject }}), {{ end }} - {{- if and $outputObject (not $method.ReturnsError) }} logzap.Object({{ $outputObject }}), {{- end }} - } - - {{ if $method.ReturnsError }} - if err != nil { - {{- if and $inputObject $outputObject }} - fields = append(fields, logzap.Object({{ $inputObject }})) - {{- end }} - m.logger.Error(fmt.Sprintf("Failed to {{ (lower $method.Name) }}. Error: %s", err), fields...) - } else { - {{- if $outputObject }} - fields = append(fields, logzap.Object({{ $outputObject }})) - {{- end }} - m.logger.Info("Successfully {{ (lower (trimSuffix "e" $method.Name)) }}ed", fields...) - } - {{ else }} - m.logger.Info("Successfully {{ (lower (trimSuffix "e" $method.Name)) }}ed", fields...) - {{ end }} - - return {{ $method.ResultsNames }} - {{- else }} - return m.next.{{ $method.Call }} - {{- end }} - } -{{ end }} diff --git a/assets/templates/middleware/log.tmpl b/assets/templates/middleware/log.tmpl new file mode 100644 index 0000000000000000000000000000000000000000..ab91909fb61f1044fe74810390a64d469a6cb614 --- /dev/null +++ b/assets/templates/middleware/log.tmpl @@ -0,0 +1,73 @@ +{{/* +Ртот шаблон предназначен только для первичной генерации LoggingMiddleware, +поскольку РѕРЅ РЅРµ может учесть РІСЃРµ сигнатуры логгируемых методов. После генерации +необходимо внести правки РІ РєРѕРґ РІ местах, помеченных 'TODO' + +Сгенерировать middleware: +```shell +gowrap gen -p git.perx.ru/perxis/perxis-go/<package_name> -i <interface> -t ../../../assets/templates/middleware/logging.tmpl -o info_logging_middleware.go -g +``` + */}} + +import ( + "fmt" + "time" + "context" + + logzap "git.perx.ru/perxis/perxis-go/zap" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + +{{ $funcName := (or .Vars.FuncName ("LoggingMiddleware")) }} +{{ $decorator := (or .Vars.DecoratorName ("loggingMiddleware")) }} +{{ $packageName := (split "." .Interface.Type)._0 }} +{{ $serviceName := (split "." .Interface.Type)._1 }} +{{ $objectName := (trimSuffix "s" (split "." .Interface.Type)._1) }} +{{ $writeMethods := list "Archive" "Create" "Delete" "Publish" "Unarchive" "Undelete" "Unpublish" "Update" "SetSchema" "Migrate" }} + +type {{ $decorator }} struct { + logger *zap.Logger + next {{ .Interface.Type }} +} + +func {{ $funcName }} (logger *zap.Logger) Middleware { + return func(next {{ .Interface.Type }}) {{ .Interface.Type }} { + return &{{ $decorator }}{ + next: next, + logger: logger.With(logzap.Component("{{ (lower $serviceName ) }}")), + } + } +} + +{{ range $method := .Interface.Methods }} +func (m *{{ $decorator }}) {{ $method.Declaration }} { + logger := m.logger.With( + {{- if $method.AcceptsContext }} + logzap.CallerFromContext(ctx), + {{ end -}} + {{- if has $method.Name $writeMethods -}} + logzap.Event({{ $packageName }}.Event{{ $objectName }}{{ $method.Name }}), + logzap.Object(TODO), + {{ end -}} + ) + + {{ $method.ResultsNames }} = m.next.{{ $method.Call }} + + {{- if $method.ReturnsError }} + if err != nil { + logger.Error("Failed to {{ (lower $method.Name) }}", zap.Error(err) + {{- if has $method.Name $writeMethods -}} + , logzap.Channels(logzap.Userlog, logzap.Syslog) + {{- end -}}) + return + } + {{ end }} + + {{ if has $method.Name $writeMethods }} + logger.Info("Successfully {{ (lower (trimSuffix "e" $method.Name)) }}ed", logzap.Channels(logzap.Userlog)) + {{ end -}} + + return {{ $method.ResultsNames }} +} +{{ end }} diff --git a/assets/templates/middleware/middleware.tmpl b/assets/templates/middleware/middleware.tmpl index bbbc20e55ca8a8763ae767b19b035f4ebee0dd68..c717d577e89331ed386cf21a1b8ba5486cd54714 100755 --- a/assets/templates/middleware/middleware.tmpl +++ b/assets/templates/middleware/middleware.tmpl @@ -6,24 +6,22 @@ import ( type Middleware func({{.Interface.Type}}) {{.Interface.Type}} -func WithLog(s {{.Interface.Type}}, logger, svcLogger *zap.Logger, log_access bool) {{.Interface.Type}} { +func WithLog(s {{.Interface.Type}}, logger *zap.Logger, log_access bool) {{.Interface.Type}} { if logger == nil { logger = zap.NewNop() } logger = logger.Named("{{ .Interface.Name }}") - - {{ if (eq $serviceName "Items") }} - if svcLogger == nil { - svcLogger = zap.NewNop() - } - s = LogInfoMiddleware(svcLogger)(s) - {{ end }} - + {{- if (has $serviceName (list "Items" "Collections") ) }} + if log_access { + s = AccessLoggingMiddleware(logger)(s) + } + s = LoggingMiddleware(logger)(s) + {{ else }} s = ErrorLoggingMiddleware(logger)(s) if log_access { s = LoggingMiddleware(logger)(s) } + {{ end -}} s = RecoveringMiddleware(logger)(s) return s } - diff --git a/log/service.go b/log/service.go index 8a39ca53e0573ac4ed0bed8bba619837d1fdf030..46e306077d8ee3476dc1e83aa30a7501494325d5 100644 --- a/log/service.go +++ b/log/service.go @@ -8,6 +8,8 @@ import ( pb "git.perx.ru/perxis/perxis-go/proto/log" ) +const ServiceName = "logs" + type Service interface { // Log метод записи логов diff --git a/log/zap/core.go b/log/zap/core.go index f2b220eab78a6cd2416408385b521c743bcefb94..070e6fb84eb3ca74cd59262eb5244054967e9307 100644 --- a/log/zap/core.go +++ b/log/zap/core.go @@ -1,6 +1,8 @@ package zap import ( + "fmt" + oid "git.perx.ru/perxis/perxis-go/id" "git.perx.ru/perxis/perxis-go/log" "git.perx.ru/perxis/perxis-go/pkg/id" @@ -76,6 +78,10 @@ func (core *Core) getEntry(entry zapcore.Entry, fields []zapcore.Field) *log.Ent ent.CallerID, _ = enc.Fields["caller"].(*oid.ObjectId) ent.Attr = enc.Fields["attr"] + if err, _ := enc.Fields["error"].(error); err != nil { + ent.Message = fmt.Sprintf("%s. Error: %s", ent.Message, err.Error()) + } + if tags, ok := enc.Fields["tags"].([]any); ok { for _, item := range tags { if tag, ok := item.(string); ok { diff --git a/pkg/collections/events.go b/pkg/collections/events.go new file mode 100644 index 0000000000000000000000000000000000000000..bdc92e7769a7cd7ffc880825caaf3098fb5495fb --- /dev/null +++ b/pkg/collections/events.go @@ -0,0 +1,8 @@ +package collections + +const ( + EventCollectionCreate = "collection_create" + EventCollectionUpdate = "collection_update" + EventCollectionDelete = "collection_delete" + EventCollectionSetSchema = "collection_set_schema" +) diff --git a/pkg/collections/middleware/access_logging_middleware.go b/pkg/collections/middleware/access_logging_middleware.go new file mode 100644 index 0000000000000000000000000000000000000000..3624955b5d3ef6201704932e623b4e8e00cc6192 --- /dev/null +++ b/pkg/collections/middleware/access_logging_middleware.go @@ -0,0 +1,175 @@ +// Code generated by gowrap. DO NOT EDIT. +// template: ../../../assets/templates/middleware/access_log.tmpl +// gowrap: http://github.com/hexdigest/gowrap + +package middleware + +//go:generate gowrap gen -p git.perx.ru/perxis/perxis-go/pkg/collections -i Collections -t ../../../assets/templates/middleware/access_log.tmpl -o access_logging_middleware.go -l "" + +import ( + "context" + "time" + + "git.perx.ru/perxis/perxis-go/pkg/auth" + "git.perx.ru/perxis/perxis-go/pkg/collections" + "git.perx.ru/perxis/perxis-go/pkg/schema" + "go.uber.org/zap" +) + +// accessLoggingMiddleware implements collections.Collections that is instrumented with logging +type accessLoggingMiddleware struct { + logger *zap.Logger + next collections.Collections +} + +// AccessLoggingMiddleware instruments an implementation of the collections.Collections with simple logging +func AccessLoggingMiddleware(logger *zap.Logger) Middleware { + return func(next collections.Collections) collections.Collections { + return &accessLoggingMiddleware{ + next: next, + logger: logger, + } + } +} + +func (m *accessLoggingMiddleware) Create(ctx context.Context, collection *collections.Collection) (created *collections.Collection, err error) { + begin := time.Now() + + m.logger.Debug("Create.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("collection", collection), + ) + + created, err = m.next.Create(ctx, collection) + + m.logger.Debug("Create.Response", + zap.Duration("time", time.Since(begin)), + zap.Reflect("created", created), + zap.Error(err), + ) + + return created, err +} + +func (m *accessLoggingMiddleware) Delete(ctx context.Context, spaceId string, envId string, collectionId string) (err error) { + begin := time.Now() + + m.logger.Debug("Delete.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("spaceId", spaceId), + zap.Reflect("envId", envId), + zap.Reflect("collectionId", collectionId), + ) + + err = m.next.Delete(ctx, spaceId, envId, collectionId) + + m.logger.Debug("Delete.Response", + zap.Duration("time", time.Since(begin)), + zap.Error(err), + ) + + return err +} + +func (m *accessLoggingMiddleware) Get(ctx context.Context, spaceId string, envId string, collectionId string, options ...*collections.GetOptions) (collection *collections.Collection, err error) { + begin := time.Now() + + m.logger.Debug("Get.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("spaceId", spaceId), + zap.Reflect("envId", envId), + zap.Reflect("collectionId", collectionId), + zap.Reflect("options", options), + ) + + collection, err = m.next.Get(ctx, spaceId, envId, collectionId, options...) + + m.logger.Debug("Get.Response", + zap.Duration("time", time.Since(begin)), + zap.Reflect("collection", collection), + zap.Error(err), + ) + + return collection, err +} + +func (m *accessLoggingMiddleware) List(ctx context.Context, spaceId string, envId string, filter *collections.Filter) (collections []*collections.Collection, err error) { + begin := time.Now() + + m.logger.Debug("List.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("spaceId", spaceId), + zap.Reflect("envId", envId), + zap.Reflect("filter", filter), + ) + + collections, err = m.next.List(ctx, spaceId, envId, filter) + + m.logger.Debug("List.Response", + zap.Duration("time", time.Since(begin)), + zap.Reflect("collections", collections), + zap.Error(err), + ) + + return collections, err +} + +func (m *accessLoggingMiddleware) SetSchema(ctx context.Context, spaceId string, envId string, collectionId string, schema *schema.Schema) (err error) { + begin := time.Now() + + m.logger.Debug("SetSchema.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("spaceId", spaceId), + zap.Reflect("envId", envId), + zap.Reflect("collectionId", collectionId), + zap.Reflect("schema", schema), + ) + + err = m.next.SetSchema(ctx, spaceId, envId, collectionId, schema) + + m.logger.Debug("SetSchema.Response", + zap.Duration("time", time.Since(begin)), + zap.Error(err), + ) + + return err +} + +func (m *accessLoggingMiddleware) SetState(ctx context.Context, spaceId string, envId string, collectionId string, state *collections.StateInfo) (err error) { + begin := time.Now() + + m.logger.Debug("SetState.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("spaceId", spaceId), + zap.Reflect("envId", envId), + zap.Reflect("collectionId", collectionId), + zap.Reflect("state", state), + ) + + err = m.next.SetState(ctx, spaceId, envId, collectionId, state) + + m.logger.Debug("SetState.Response", + zap.Duration("time", time.Since(begin)), + zap.Error(err), + ) + + return err +} + +func (m *accessLoggingMiddleware) Update(ctx context.Context, coll *collections.Collection) (err error) { + begin := time.Now() + + m.logger.Debug("Update.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("coll", coll), + ) + + err = m.next.Update(ctx, coll) + + m.logger.Debug("Update.Response", + zap.Duration("time", time.Since(begin)), + zap.Error(err), + ) + + return err +} diff --git a/pkg/collections/middleware/error_logging_middleware.go b/pkg/collections/middleware/error_logging_middleware.go deleted file mode 100644 index 0491250639063a0e4d229c711c19b36223b9b2e4..0000000000000000000000000000000000000000 --- a/pkg/collections/middleware/error_logging_middleware.go +++ /dev/null @@ -1,101 +0,0 @@ -package middleware - -// Code generated by gowrap. DO NOT EDIT. -// template: ../../../assets/templates/middleware/error_log -// gowrap: http://github.com/hexdigest/gowrap - -//go:generate gowrap gen -p git.perx.ru/perxis/perxis-go/pkg/collections -i Collections -t ../../../assets/templates/middleware/error_log -o error_logging_middleware.go -l "" - -import ( - "context" - - "git.perx.ru/perxis/perxis-go/pkg/collections" - "git.perx.ru/perxis/perxis-go/pkg/schema" - "go.uber.org/zap" -) - -// errorLoggingMiddleware implements collections.Collections that is instrumented with logging -type errorLoggingMiddleware struct { - logger *zap.Logger - next collections.Collections -} - -// ErrorLoggingMiddleware instruments an implementation of the collections.Collections with simple logging -func ErrorLoggingMiddleware(logger *zap.Logger) Middleware { - return func(next collections.Collections) collections.Collections { - return &errorLoggingMiddleware{ - next: next, - logger: logger, - } - } -} - -func (m *errorLoggingMiddleware) Create(ctx context.Context, collection *collections.Collection) (created *collections.Collection, err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.Create(ctx, collection) -} - -func (m *errorLoggingMiddleware) Delete(ctx context.Context, spaceId string, envId string, collectionId string) (err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.Delete(ctx, spaceId, envId, collectionId) -} - -func (m *errorLoggingMiddleware) Get(ctx context.Context, spaceId string, envId string, collectionId string, options ...*collections.GetOptions) (collection *collections.Collection, err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.Get(ctx, spaceId, envId, collectionId, options...) -} - -func (m *errorLoggingMiddleware) List(ctx context.Context, spaceId string, envId string, filter *collections.Filter) (collections []*collections.Collection, err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.List(ctx, spaceId, envId, filter) -} - -func (m *errorLoggingMiddleware) SetSchema(ctx context.Context, spaceId string, envId string, collectionId string, schema *schema.Schema) (err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.SetSchema(ctx, spaceId, envId, collectionId, schema) -} - -func (m *errorLoggingMiddleware) SetState(ctx context.Context, spaceId string, envId string, collectionId string, state *collections.StateInfo) (err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.SetState(ctx, spaceId, envId, collectionId, state) -} - -func (m *errorLoggingMiddleware) Update(ctx context.Context, coll *collections.Collection) (err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.Update(ctx, coll) -} diff --git a/pkg/collections/middleware/logging_middleware.go b/pkg/collections/middleware/logging_middleware.go index bc3e41070fc56e0a4ec2a75f073f9696a88560fb..c5e2e2fb3e5bf604fdb57c8484f4a20289029da6 100644 --- a/pkg/collections/middleware/logging_middleware.go +++ b/pkg/collections/middleware/logging_middleware.go @@ -1,303 +1,140 @@ -package middleware - // Code generated by gowrap. DO NOT EDIT. -// template: ../../../assets/templates/middleware/access_log +// template: ../../../assets/templates/middleware/log.tmpl // gowrap: http://github.com/hexdigest/gowrap -//go:generate gowrap gen -p git.perx.ru/perxis/perxis-go/pkg/collections -i Collections -t ../../../assets/templates/middleware/access_log -o logging_middleware.go -l "" +package middleware + +//go:generate gowrap gen -p git.perx.ru/perxis/perxis-go/pkg/collections -i Collections -t ../../../assets/templates/middleware/log.tmpl -o logging_middleware.go -l "" import ( "context" - "fmt" - "time" - "git.perx.ru/perxis/perxis-go/pkg/auth" + "git.perx.ru/perxis/perxis-go/id" "git.perx.ru/perxis/perxis-go/pkg/collections" "git.perx.ru/perxis/perxis-go/pkg/schema" + logzap "git.perx.ru/perxis/perxis-go/zap" "go.uber.org/zap" - "go.uber.org/zap/zapcore" ) -// loggingMiddleware implements collections.Collections that is instrumented with logging type loggingMiddleware struct { logger *zap.Logger next collections.Collections } -// LoggingMiddleware instruments an implementation of the collections.Collections with simple logging func LoggingMiddleware(logger *zap.Logger) Middleware { return func(next collections.Collections) collections.Collections { return &loggingMiddleware{ next: next, - logger: logger, + logger: logger.With(logzap.Component("collections")), } } } func (m *loggingMiddleware) Create(ctx context.Context, collection *collections.Collection) (created *collections.Collection, err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "collection": collection} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Create.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Event(collections.EventCollectionCreate), + ) created, err = m.next.Create(ctx, collection) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), + if err != nil { + logger.Error("Failed to create", zap.Error(err), logzap.Object(collection), logzap.Channels(logzap.Userlog, logzap.Syslog)) + return } - for k, v := range map[string]interface{}{ - "created": created, - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Create.Response", fields...) - + logger.Info("Successfully created", logzap.Object(created), logzap.Channels(logzap.Userlog)) return created, err } func (m *loggingMiddleware) Delete(ctx context.Context, spaceId string, envId string, collectionId string) (err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "spaceId": spaceId, - "envId": envId, - "collectionId": collectionId} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Delete.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Event(collections.EventCollectionDelete), + logzap.Object(id.NewCollectionId(spaceId, envId, collectionId)), + ) err = m.next.Delete(ctx, spaceId, envId, collectionId) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), - } - - for k, v := range map[string]interface{}{ - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) + if err != nil { + logger.Error("Failed to delete", zap.Error(err), logzap.Channels(logzap.Userlog, logzap.Syslog)) + return } - m.logger.Debug("Delete.Response", fields...) - + logger.Info("Successfully deleted", logzap.Channels(logzap.Userlog)) return err } func (m *loggingMiddleware) Get(ctx context.Context, spaceId string, envId string, collectionId string, options ...*collections.GetOptions) (collection *collections.Collection, err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "spaceId": spaceId, - "envId": envId, - "collectionId": collectionId, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Get.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + ) collection, err = m.next.Get(ctx, spaceId, envId, collectionId, options...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), - } - - for k, v := range map[string]interface{}{ - "collection": collection, - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) + if err != nil { + logger.Error("Failed to get", zap.Error(err)) + return } - m.logger.Debug("Get.Response", fields...) - return collection, err } func (m *loggingMiddleware) List(ctx context.Context, spaceId string, envId string, filter *collections.Filter) (collections []*collections.Collection, err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "spaceId": spaceId, - "envId": envId, - "filter": filter} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("List.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + ) collections, err = m.next.List(ctx, spaceId, envId, filter) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), - } - - for k, v := range map[string]interface{}{ - "collections": collections, - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) + if err != nil { + logger.Error("Failed to list", zap.Error(err)) + return } - m.logger.Debug("List.Response", fields...) - return collections, err } func (m *loggingMiddleware) SetSchema(ctx context.Context, spaceId string, envId string, collectionId string, schema *schema.Schema) (err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "spaceId": spaceId, - "envId": envId, - "collectionId": collectionId, - "schema": schema} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("SetSchema.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Event(collections.EventCollectionSetSchema), + logzap.Object(id.NewCollectionId(spaceId, envId, collectionId)), + ) err = m.next.SetSchema(ctx, spaceId, envId, collectionId, schema) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), + if err != nil { + logger.Error("Failed to setschema", zap.Error(err), logzap.Channels(logzap.Userlog, logzap.Syslog)) + return } - for k, v := range map[string]interface{}{ - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("SetSchema.Response", fields...) - + logger.Info("Successfully setschemaed", logzap.Channels(logzap.Userlog)) return err } func (m *loggingMiddleware) SetState(ctx context.Context, spaceId string, envId string, collectionId string, state *collections.StateInfo) (err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "spaceId": spaceId, - "envId": envId, - "collectionId": collectionId, - "state": state} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("SetState.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + ) err = m.next.SetState(ctx, spaceId, envId, collectionId, state) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), - } - - for k, v := range map[string]interface{}{ - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) + if err != nil { + logger.Error("Failed to setstate", zap.Error(err)) + return } - m.logger.Debug("SetState.Response", fields...) - return err } func (m *loggingMiddleware) Update(ctx context.Context, coll *collections.Collection) (err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "coll": coll} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Update.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Event(collections.EventCollectionUpdate), + logzap.Object(coll), + ) err = m.next.Update(ctx, coll) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), + if err != nil { + logger.Error("Failed to update", zap.Error(err), logzap.Channels(logzap.Userlog, logzap.Syslog)) + return } - for k, v := range map[string]interface{}{ - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Update.Response", fields...) - + logger.Info("Successfully updated", logzap.Channels(logzap.Userlog)) return err } diff --git a/pkg/collections/middleware/middleware.go b/pkg/collections/middleware/middleware.go index b581ce74b6071c707cc96fe9f11656bece37eb99..22514e7c93ec032847590821bfb2ba7467462f63 100644 --- a/pkg/collections/middleware/middleware.go +++ b/pkg/collections/middleware/middleware.go @@ -1,10 +1,10 @@ // Code generated by gowrap. DO NOT EDIT. -// template: ../../../assets/templates/middleware/middleware +// template: ../../../assets/templates/middleware/middleware.tmpl // gowrap: http://github.com/hexdigest/gowrap package middleware -//go:generate gowrap gen -p git.perx.ru/perxis/perxis-go/pkg/collections -i Collections -t ../../../assets/templates/middleware/middleware -o middleware.go -l "" +//go:generate gowrap gen -p git.perx.ru/perxis/perxis-go/pkg/collections -i Collections -t ../../../assets/templates/middleware/middleware.tmpl -o middleware.go -l "" import ( "git.perx.ru/perxis/perxis-go/pkg/collections" @@ -17,12 +17,11 @@ func WithLog(s collections.Collections, logger *zap.Logger, log_access bool) col if logger == nil { logger = zap.NewNop() } - logger = logger.Named("Collections") - s = ErrorLoggingMiddleware(logger)(s) if log_access { - s = LoggingMiddleware(logger)(s) + s = AccessLoggingMiddleware(logger)(s) } + s = LoggingMiddleware(logger)(s) s = RecoveringMiddleware(logger)(s) return s } diff --git a/pkg/items/events.go b/pkg/items/events.go index 88da05d86dee157c1157f2af19d8459516441d76..9a1eb9249ff9224eaa217fdfd8bf1cb12c9d68fc 100644 --- a/pkg/items/events.go +++ b/pkg/items/events.go @@ -7,14 +7,14 @@ import ( ) const ( - EventCreateItem = "create_item" - EventUpdateItem = "update_item" - EventPublishItem = "publish_item" - EventUnpublishItem = "unpublish_item" - EventDeleteItem = "delete_item" - EventUndeleteItem = "undelete_item" - EventArchiveItem = "archive_item" - EventUnarchiveItem = "unarchive_item" + EventItemCreate = "create_item" + EventItemUpdate = "update_item" + EventItemPublish = "publish_item" + EventItemUnpublish = "unpublish_item" + EventItemDelete = "delete_item" + EventItemUndelete = "item_undelete" + EventItemArchive = "item_archive" + EventItemUnarchive = "item_unarchive" DefaultEventSubject = "content.{{.EventType}}.{{.SpaceID}}.{{.EnvID}}.{{.CollectionID}}.{{.ItemID}}" ) diff --git a/pkg/items/middleware/access_logging_middleware.go b/pkg/items/middleware/access_logging_middleware.go new file mode 100644 index 0000000000000000000000000000000000000000..2342a6d99249f427aa0f4ad6b4220a43ba872a4f --- /dev/null +++ b/pkg/items/middleware/access_logging_middleware.go @@ -0,0 +1,418 @@ +// Code generated by gowrap. DO NOT EDIT. +// template: ../../../assets/templates/middleware/access_log.tmpl +// gowrap: http://github.com/hexdigest/gowrap + +package middleware + +//go:generate gowrap gen -p git.perx.ru/perxis/perxis-go/pkg/items -i Items -t ../../../assets/templates/middleware/access_log.tmpl -o access_logging_middleware.go -l "" + +import ( + "context" + "time" + + "git.perx.ru/perxis/perxis-go/pkg/auth" + "git.perx.ru/perxis/perxis-go/pkg/items" + "git.perx.ru/perxis/perxis-go/pkg/schema" + "go.uber.org/zap" +) + +// accessLoggingMiddleware implements items.Items that is instrumented with logging +type accessLoggingMiddleware struct { + logger *zap.Logger + next items.Items +} + +// AccessLoggingMiddleware instruments an implementation of the items.Items with simple logging +func AccessLoggingMiddleware(logger *zap.Logger) Middleware { + return func(next items.Items) items.Items { + return &accessLoggingMiddleware{ + next: next, + logger: logger, + } + } +} + +func (m *accessLoggingMiddleware) Aggregate(ctx context.Context, spaceId string, envId string, collectionId string, filter *items.Filter, options ...*items.AggregateOptions) (result map[string]interface{}, err error) { + begin := time.Now() + + m.logger.Debug("Aggregate.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("spaceId", spaceId), + zap.Reflect("envId", envId), + zap.Reflect("collectionId", collectionId), + zap.Reflect("filter", filter), + zap.Reflect("options", options), + ) + + result, err = m.next.Aggregate(ctx, spaceId, envId, collectionId, filter, options...) + + m.logger.Debug("Aggregate.Response", + zap.Duration("time", time.Since(begin)), + zap.Reflect("result", result), + zap.Error(err), + ) + + return result, err +} + +func (m *accessLoggingMiddleware) AggregatePublished(ctx context.Context, spaceId string, envId string, collectionId string, filter *items.Filter, options ...*items.AggregatePublishedOptions) (result map[string]interface{}, err error) { + begin := time.Now() + + m.logger.Debug("AggregatePublished.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("spaceId", spaceId), + zap.Reflect("envId", envId), + zap.Reflect("collectionId", collectionId), + zap.Reflect("filter", filter), + zap.Reflect("options", options), + ) + + result, err = m.next.AggregatePublished(ctx, spaceId, envId, collectionId, filter, options...) + + m.logger.Debug("AggregatePublished.Response", + zap.Duration("time", time.Since(begin)), + zap.Reflect("result", result), + zap.Error(err), + ) + + return result, err +} + +func (m *accessLoggingMiddleware) Archive(ctx context.Context, item *items.Item, options ...*items.ArchiveOptions) (err error) { + begin := time.Now() + + m.logger.Debug("Archive.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("item", item), + zap.Reflect("options", options), + ) + + err = m.next.Archive(ctx, item, options...) + + m.logger.Debug("Archive.Response", + zap.Duration("time", time.Since(begin)), + zap.Error(err), + ) + + return err +} + +func (m *accessLoggingMiddleware) Create(ctx context.Context, item *items.Item, opts ...*items.CreateOptions) (created *items.Item, err error) { + begin := time.Now() + + m.logger.Debug("Create.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("item", item), + zap.Reflect("opts", opts), + ) + + created, err = m.next.Create(ctx, item, opts...) + + m.logger.Debug("Create.Response", + zap.Duration("time", time.Since(begin)), + zap.Reflect("created", created), + zap.Error(err), + ) + + return created, err +} + +func (m *accessLoggingMiddleware) Delete(ctx context.Context, item *items.Item, options ...*items.DeleteOptions) (err error) { + begin := time.Now() + + m.logger.Debug("Delete.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("item", item), + zap.Reflect("options", options), + ) + + err = m.next.Delete(ctx, item, options...) + + m.logger.Debug("Delete.Response", + zap.Duration("time", time.Since(begin)), + zap.Error(err), + ) + + return err +} + +func (m *accessLoggingMiddleware) Find(ctx context.Context, spaceId string, envId string, collectionId string, filter *items.Filter, options ...*items.FindOptions) (items []*items.Item, total int, err error) { + begin := time.Now() + + m.logger.Debug("Find.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("spaceId", spaceId), + zap.Reflect("envId", envId), + zap.Reflect("collectionId", collectionId), + zap.Reflect("filter", filter), + zap.Reflect("options", options), + ) + + items, total, err = m.next.Find(ctx, spaceId, envId, collectionId, filter, options...) + + m.logger.Debug("Find.Response", + zap.Duration("time", time.Since(begin)), + zap.Reflect("items", items), + zap.Reflect("total", total), + zap.Error(err), + ) + + return items, total, err +} + +func (m *accessLoggingMiddleware) FindArchived(ctx context.Context, spaceId string, envId string, collectionId string, filter *items.Filter, options ...*items.FindArchivedOptions) (items []*items.Item, total int, err error) { + begin := time.Now() + + m.logger.Debug("FindArchived.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("spaceId", spaceId), + zap.Reflect("envId", envId), + zap.Reflect("collectionId", collectionId), + zap.Reflect("filter", filter), + zap.Reflect("options", options), + ) + + items, total, err = m.next.FindArchived(ctx, spaceId, envId, collectionId, filter, options...) + + m.logger.Debug("FindArchived.Response", + zap.Duration("time", time.Since(begin)), + zap.Reflect("items", items), + zap.Reflect("total", total), + zap.Error(err), + ) + + return items, total, err +} + +func (m *accessLoggingMiddleware) FindPublished(ctx context.Context, spaceId string, envId string, collectionId string, filter *items.Filter, options ...*items.FindPublishedOptions) (items []*items.Item, total int, err error) { + begin := time.Now() + + m.logger.Debug("FindPublished.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("spaceId", spaceId), + zap.Reflect("envId", envId), + zap.Reflect("collectionId", collectionId), + zap.Reflect("filter", filter), + zap.Reflect("options", options), + ) + + items, total, err = m.next.FindPublished(ctx, spaceId, envId, collectionId, filter, options...) + + m.logger.Debug("FindPublished.Response", + zap.Duration("time", time.Since(begin)), + zap.Reflect("items", items), + zap.Reflect("total", total), + zap.Error(err), + ) + + return items, total, err +} + +func (m *accessLoggingMiddleware) Get(ctx context.Context, spaceId string, envId string, collectionId string, itemId string, options ...*items.GetOptions) (item *items.Item, err error) { + begin := time.Now() + + m.logger.Debug("Get.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("spaceId", spaceId), + zap.Reflect("envId", envId), + zap.Reflect("collectionId", collectionId), + zap.Reflect("itemId", itemId), + zap.Reflect("options", options), + ) + + item, err = m.next.Get(ctx, spaceId, envId, collectionId, itemId, options...) + + m.logger.Debug("Get.Response", + zap.Duration("time", time.Since(begin)), + zap.Reflect("item", item), + zap.Error(err), + ) + + return item, err +} + +func (m *accessLoggingMiddleware) GetPublished(ctx context.Context, spaceId string, envId string, collectionId string, itemId string, options ...*items.GetPublishedOptions) (item *items.Item, err error) { + begin := time.Now() + + m.logger.Debug("GetPublished.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("spaceId", spaceId), + zap.Reflect("envId", envId), + zap.Reflect("collectionId", collectionId), + zap.Reflect("itemId", itemId), + zap.Reflect("options", options), + ) + + item, err = m.next.GetPublished(ctx, spaceId, envId, collectionId, itemId, options...) + + m.logger.Debug("GetPublished.Response", + zap.Duration("time", time.Since(begin)), + zap.Reflect("item", item), + zap.Error(err), + ) + + return item, err +} + +func (m *accessLoggingMiddleware) GetRevision(ctx context.Context, spaceId string, envId string, collectionId string, itemId string, revisionId string, options ...*items.GetRevisionOptions) (item *items.Item, err error) { + begin := time.Now() + + m.logger.Debug("GetRevision.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("spaceId", spaceId), + zap.Reflect("envId", envId), + zap.Reflect("collectionId", collectionId), + zap.Reflect("itemId", itemId), + zap.Reflect("revisionId", revisionId), + zap.Reflect("options", options), + ) + + item, err = m.next.GetRevision(ctx, spaceId, envId, collectionId, itemId, revisionId, options...) + + m.logger.Debug("GetRevision.Response", + zap.Duration("time", time.Since(begin)), + zap.Reflect("item", item), + zap.Error(err), + ) + + return item, err +} + +func (m *accessLoggingMiddleware) Introspect(ctx context.Context, item *items.Item, opts ...*items.IntrospectOptions) (itm *items.Item, sch *schema.Schema, err error) { + begin := time.Now() + + m.logger.Debug("Introspect.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("item", item), + zap.Reflect("opts", opts), + ) + + itm, sch, err = m.next.Introspect(ctx, item, opts...) + + m.logger.Debug("Introspect.Response", + zap.Duration("time", time.Since(begin)), + zap.Reflect("itm", itm), + zap.Reflect("sch", sch), + zap.Error(err), + ) + + return itm, sch, err +} + +func (m *accessLoggingMiddleware) ListRevisions(ctx context.Context, spaceId string, envId string, collectionId string, itemId string, options ...*items.ListRevisionsOptions) (items []*items.Item, err error) { + begin := time.Now() + + m.logger.Debug("ListRevisions.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("spaceId", spaceId), + zap.Reflect("envId", envId), + zap.Reflect("collectionId", collectionId), + zap.Reflect("itemId", itemId), + zap.Reflect("options", options), + ) + + items, err = m.next.ListRevisions(ctx, spaceId, envId, collectionId, itemId, options...) + + m.logger.Debug("ListRevisions.Response", + zap.Duration("time", time.Since(begin)), + zap.Reflect("items", items), + zap.Error(err), + ) + + return items, err +} + +func (m *accessLoggingMiddleware) Publish(ctx context.Context, item *items.Item, options ...*items.PublishOptions) (err error) { + begin := time.Now() + + m.logger.Debug("Publish.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("item", item), + zap.Reflect("options", options), + ) + + err = m.next.Publish(ctx, item, options...) + + m.logger.Debug("Publish.Response", + zap.Duration("time", time.Since(begin)), + zap.Error(err), + ) + + return err +} + +func (m *accessLoggingMiddleware) Unarchive(ctx context.Context, item *items.Item, options ...*items.UnarchiveOptions) (err error) { + begin := time.Now() + + m.logger.Debug("Unarchive.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("item", item), + zap.Reflect("options", options), + ) + + err = m.next.Unarchive(ctx, item, options...) + + m.logger.Debug("Unarchive.Response", + zap.Duration("time", time.Since(begin)), + zap.Error(err), + ) + + return err +} + +func (m *accessLoggingMiddleware) Undelete(ctx context.Context, item *items.Item, options ...*items.UndeleteOptions) (err error) { + begin := time.Now() + + m.logger.Debug("Undelete.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("item", item), + zap.Reflect("options", options), + ) + + err = m.next.Undelete(ctx, item, options...) + + m.logger.Debug("Undelete.Response", + zap.Duration("time", time.Since(begin)), + zap.Error(err), + ) + + return err +} + +func (m *accessLoggingMiddleware) Unpublish(ctx context.Context, item *items.Item, options ...*items.UnpublishOptions) (err error) { + begin := time.Now() + + m.logger.Debug("Unpublish.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("item", item), + zap.Reflect("options", options), + ) + + err = m.next.Unpublish(ctx, item, options...) + + m.logger.Debug("Unpublish.Response", + zap.Duration("time", time.Since(begin)), + zap.Error(err), + ) + + return err +} + +func (m *accessLoggingMiddleware) Update(ctx context.Context, item *items.Item, options ...*items.UpdateOptions) (err error) { + begin := time.Now() + + m.logger.Debug("Update.Request", + zap.Reflect("principal", auth.GetPrincipal(ctx)), + zap.Reflect("item", item), + zap.Reflect("options", options), + ) + + err = m.next.Update(ctx, item, options...) + + m.logger.Debug("Update.Response", + zap.Duration("time", time.Since(begin)), + zap.Error(err), + ) + + return err +} diff --git a/pkg/items/middleware/error_logging_middleware.go b/pkg/items/middleware/error_logging_middleware.go deleted file mode 100644 index 345d22ca2727d1516e4a7176e885195ab38f1d20..0000000000000000000000000000000000000000 --- a/pkg/items/middleware/error_logging_middleware.go +++ /dev/null @@ -1,211 +0,0 @@ -// Code generated by gowrap. DO NOT EDIT. -// template: ../../../assets/templates/middleware/error_log -// gowrap: http://github.com/hexdigest/gowrap - -package middleware - -//go:generate gowrap gen -p git.perx.ru/perxis/perxis-go/pkg/items -i Items -t ../../../assets/templates/middleware/error_log -o error_logging_middleware.go -l "" - -import ( - "context" - - "git.perx.ru/perxis/perxis-go/pkg/items" - "git.perx.ru/perxis/perxis-go/pkg/schema" - "go.uber.org/zap" -) - -// errorLoggingMiddleware implements items.Items that is instrumented with logging -type errorLoggingMiddleware struct { - logger *zap.Logger - next items.Items -} - -// ErrorLoggingMiddleware instruments an implementation of the items.Items with simple logging -func ErrorLoggingMiddleware(logger *zap.Logger) Middleware { - return func(next items.Items) items.Items { - return &errorLoggingMiddleware{ - next: next, - logger: logger, - } - } -} - -func (m *errorLoggingMiddleware) Aggregate(ctx context.Context, spaceId string, envId string, collectionId string, filter *items.Filter, options ...*items.AggregateOptions) (result map[string]interface{}, err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.Aggregate(ctx, spaceId, envId, collectionId, filter, options...) -} - -func (m *errorLoggingMiddleware) AggregatePublished(ctx context.Context, spaceId string, envId string, collectionId string, filter *items.Filter, options ...*items.AggregatePublishedOptions) (result map[string]interface{}, err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.AggregatePublished(ctx, spaceId, envId, collectionId, filter, options...) -} - -func (m *errorLoggingMiddleware) Archive(ctx context.Context, item *items.Item, options ...*items.ArchiveOptions) (err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.Archive(ctx, item, options...) -} - -func (m *errorLoggingMiddleware) Create(ctx context.Context, item *items.Item, opts ...*items.CreateOptions) (created *items.Item, err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.Create(ctx, item, opts...) -} - -func (m *errorLoggingMiddleware) Delete(ctx context.Context, item *items.Item, options ...*items.DeleteOptions) (err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.Delete(ctx, item, options...) -} - -func (m *errorLoggingMiddleware) Find(ctx context.Context, spaceId string, envId string, collectionId string, filter *items.Filter, options ...*items.FindOptions) (items []*items.Item, total int, err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.Find(ctx, spaceId, envId, collectionId, filter, options...) -} - -func (m *errorLoggingMiddleware) FindArchived(ctx context.Context, spaceId string, envId string, collectionId string, filter *items.Filter, options ...*items.FindArchivedOptions) (items []*items.Item, total int, err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.FindArchived(ctx, spaceId, envId, collectionId, filter, options...) -} - -func (m *errorLoggingMiddleware) FindPublished(ctx context.Context, spaceId string, envId string, collectionId string, filter *items.Filter, options ...*items.FindPublishedOptions) (items []*items.Item, total int, err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.FindPublished(ctx, spaceId, envId, collectionId, filter, options...) -} - -func (m *errorLoggingMiddleware) Get(ctx context.Context, spaceId string, envId string, collectionId string, itemId string, options ...*items.GetOptions) (item *items.Item, err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.Get(ctx, spaceId, envId, collectionId, itemId, options...) -} - -func (m *errorLoggingMiddleware) GetPublished(ctx context.Context, spaceId string, envId string, collectionId string, itemId string, options ...*items.GetPublishedOptions) (item *items.Item, err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.GetPublished(ctx, spaceId, envId, collectionId, itemId, options...) -} - -func (m *errorLoggingMiddleware) GetRevision(ctx context.Context, spaceId string, envId string, collectionId string, itemId string, revisionId string, options ...*items.GetRevisionOptions) (item *items.Item, err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.GetRevision(ctx, spaceId, envId, collectionId, itemId, revisionId, options...) -} - -func (m *errorLoggingMiddleware) Introspect(ctx context.Context, item *items.Item, opts ...*items.IntrospectOptions) (itm *items.Item, sch *schema.Schema, err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.Introspect(ctx, item, opts...) -} - -func (m *errorLoggingMiddleware) ListRevisions(ctx context.Context, spaceId string, envId string, collectionId string, itemId string, options ...*items.ListRevisionsOptions) (items []*items.Item, err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.ListRevisions(ctx, spaceId, envId, collectionId, itemId, options...) -} - -func (m *errorLoggingMiddleware) Publish(ctx context.Context, item *items.Item, options ...*items.PublishOptions) (err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.Publish(ctx, item, options...) -} - -func (m *errorLoggingMiddleware) Unarchive(ctx context.Context, item *items.Item, options ...*items.UnarchiveOptions) (err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.Unarchive(ctx, item, options...) -} - -func (m *errorLoggingMiddleware) Undelete(ctx context.Context, item *items.Item, options ...*items.UndeleteOptions) (err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.Undelete(ctx, item, options...) -} - -func (m *errorLoggingMiddleware) Unpublish(ctx context.Context, item *items.Item, options ...*items.UnpublishOptions) (err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.Unpublish(ctx, item, options...) -} - -func (m *errorLoggingMiddleware) Update(ctx context.Context, item *items.Item, options ...*items.UpdateOptions) (err error) { - logger := m.logger - defer func() { - if err != nil { - logger.Warn("response error", zap.Error(err)) - } - }() - return m.next.Update(ctx, item, options...) -} diff --git a/pkg/items/middleware/log_info_middleware.go b/pkg/items/middleware/log_info_middleware.go deleted file mode 100644 index c80d51d49078afdfe0cf8138c34d913f9b9408ba..0000000000000000000000000000000000000000 --- a/pkg/items/middleware/log_info_middleware.go +++ /dev/null @@ -1,161 +0,0 @@ -package middleware - -import ( - "context" - "fmt" - - "git.perx.ru/perxis/perxis-go/pkg/items" - logzap "git.perx.ru/perxis/perxis-go/pkg/log/zap" - "go.uber.org/zap" - "go.uber.org/zap/zapcore" -) - -type logInfoMiddleware struct { - items.Items - logger *zap.Logger -} - -func LogInfoMiddleware(logger *zap.Logger) Middleware { - return func(next items.Items) items.Items { - return &logInfoMiddleware{ - Items: next, - logger: logger.With(logzap.Component("Items")), - } - } -} - -func (m *logInfoMiddleware) Archive(ctx context.Context, item *items.Item, options ...*items.ArchiveOptions) (err error) { - err = m.Items.Archive(ctx, item, options...) - - fields := []zapcore.Field{ - logzap.Event(items.EventArchiveItem), - logzap.CallerFromContext(ctx), - } - - if err != nil { - m.logger.Error(fmt.Sprintf("Failed to archive. Error: %s", err), append(fields, logzap.Object(item))...) - } else { - m.logger.Info("Successfully archived", append(fields, logzap.Object(item))...) - } - - return err -} - -func (m *logInfoMiddleware) Create(ctx context.Context, item *items.Item, opts ...*items.CreateOptions) (created *items.Item, err error) { - created, err = m.Items.Create(ctx, item, opts...) - - fields := []zapcore.Field{ - logzap.Event(items.EventCreateItem), - logzap.CallerFromContext(ctx), - } - - if err != nil { - m.logger.Error(fmt.Sprintf("Failed to create. Error: %s", err), append(fields, logzap.Object(item))...) - } else { - m.logger.Info("Successfully created", append(fields, logzap.Object(created))...) - } - - return created, err -} - -func (m *logInfoMiddleware) Delete(ctx context.Context, item *items.Item, options ...*items.DeleteOptions) (err error) { - err = m.Items.Delete(ctx, item, options...) - - fields := []zapcore.Field{ - logzap.Event(items.EventDeleteItem), - logzap.CallerFromContext(ctx), - } - - if err != nil { - m.logger.Error(fmt.Sprintf("Failed to delete. Error: %s", err), append(fields, logzap.Object(item))...) - } else { - m.logger.Info("Successfully deleted", append(fields, logzap.Object(item))...) - } - - return err -} - -func (m *logInfoMiddleware) Publish(ctx context.Context, item *items.Item, options ...*items.PublishOptions) (err error) { - err = m.Items.Publish(ctx, item, options...) - - fields := []zapcore.Field{ - logzap.Event(items.EventPublishItem), - logzap.CallerFromContext(ctx), - } - - if err != nil { - m.logger.Error(fmt.Sprintf("Failed to publish. Error: %s", err), append(fields, logzap.Object(item))...) - } else { - m.logger.Info("Successfully published", append(fields, logzap.Object(item))...) - } - - return err -} - -func (m *logInfoMiddleware) Unarchive(ctx context.Context, item *items.Item, options ...*items.UnarchiveOptions) (err error) { - err = m.Items.Unarchive(ctx, item, options...) - - fields := []zapcore.Field{ - logzap.Event(items.EventUnarchiveItem), - logzap.CallerFromContext(ctx), - } - - if err != nil { - m.logger.Error(fmt.Sprintf("Failed to unarchive. Error: %s", err), append(fields, logzap.Object(item))...) - } else { - m.logger.Info("Successfully unarchived", append(fields, logzap.Object(item))...) - } - - return err -} - -func (m *logInfoMiddleware) Undelete(ctx context.Context, item *items.Item, options ...*items.UndeleteOptions) (err error) { - err = m.Items.Undelete(ctx, item, options...) - - fields := []zapcore.Field{ - logzap.Event(items.EventUndeleteItem), - logzap.CallerFromContext(ctx), - } - - if err != nil { - m.logger.Error(fmt.Sprintf("Failed to undelete. Error: %s", err), append(fields, logzap.Object(item))...) - } else { - m.logger.Info("Successfully undeleted", append(fields, logzap.Object(item))...) - } - - return err -} - -func (m *logInfoMiddleware) Unpublish(ctx context.Context, item *items.Item, options ...*items.UnpublishOptions) (err error) { - err = m.Items.Unpublish(ctx, item, options...) - - fields := []zapcore.Field{ - logzap.Event(items.EventUnpublishItem), - logzap.CallerFromContext(ctx), - } - - if err != nil { - m.logger.Error(fmt.Sprintf("Failed to unpublish. Error: %s", err), append(fields, logzap.Object(item))...) - } else { - m.logger.Info("Successfully unpublished", append(fields, logzap.Object(item))...) - } - - return err -} - -func (m *logInfoMiddleware) Update(ctx context.Context, item *items.Item, options ...*items.UpdateOptions) (err error) { - err = m.Items.Update(ctx, item, options...) - - fields := []zapcore.Field{ - logzap.Event(items.EventUpdateItem), - logzap.CallerFromContext(ctx), - } - - if err != nil { - m.logger.Error(fmt.Sprintf("Failed to update. Error: %s", err), append(fields, logzap.Object(item))...) - } else { - m.logger.Info("Successfully updated", append(fields, logzap.Object(item))...) - } - - return err -} diff --git a/pkg/items/middleware/logging_middleware.go b/pkg/items/middleware/logging_middleware.go index 6ed28f90053eab68a44b1e5ac79d5228d7bfe9be..8870912f5ee01671c026431c80fe1e091b36bbdd 100644 --- a/pkg/items/middleware/logging_middleware.go +++ b/pkg/items/middleware/logging_middleware.go @@ -1,744 +1,306 @@ -// Code generated by gowrap. DO NOT EDIT. -// template: ../../../assets/templates/middleware/access_log -// gowrap: http://github.com/hexdigest/gowrap - package middleware -//go:generate gowrap gen -p git.perx.ru/perxis/perxis-go/pkg/items -i Items -t ../../../assets/templates/middleware/access_log -o logging_middleware.go -l "" - import ( "context" - "fmt" - "time" - "git.perx.ru/perxis/perxis-go/pkg/auth" + "git.perx.ru/perxis/perxis-go/id" "git.perx.ru/perxis/perxis-go/pkg/items" "git.perx.ru/perxis/perxis-go/pkg/schema" + logzap "git.perx.ru/perxis/perxis-go/zap" "go.uber.org/zap" - "go.uber.org/zap/zapcore" ) -// loggingMiddleware implements items.Items that is instrumented with logging type loggingMiddleware struct { logger *zap.Logger next items.Items } -// LoggingMiddleware instruments an implementation of the items.Items with simple logging func LoggingMiddleware(logger *zap.Logger) Middleware { return func(next items.Items) items.Items { return &loggingMiddleware{ next: next, - logger: logger, + logger: logger.With(logzap.Component("items")), } } } func (m *loggingMiddleware) Aggregate(ctx context.Context, spaceId string, envId string, collectionId string, filter *items.Filter, options ...*items.AggregateOptions) (result map[string]interface{}, err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "spaceId": spaceId, - "envId": envId, - "collectionId": collectionId, - "filter": filter, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Aggregate.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + ) result, err = m.next.Aggregate(ctx, spaceId, envId, collectionId, filter, options...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), + if err != nil { + logger.Error("Failed to aggregate", zap.Error(err)) + return } - for k, v := range map[string]interface{}{ - "result": result, - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Aggregate.Response", fields...) - return result, err } func (m *loggingMiddleware) AggregatePublished(ctx context.Context, spaceId string, envId string, collectionId string, filter *items.Filter, options ...*items.AggregatePublishedOptions) (result map[string]interface{}, err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "spaceId": spaceId, - "envId": envId, - "collectionId": collectionId, - "filter": filter, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("AggregatePublished.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + ) result, err = m.next.AggregatePublished(ctx, spaceId, envId, collectionId, filter, options...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), + if err != nil { + logger.Error("Failed to aggregate_published", zap.Error(err)) + return } - for k, v := range map[string]interface{}{ - "result": result, - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("AggregatePublished.Response", fields...) - return result, err } func (m *loggingMiddleware) Archive(ctx context.Context, item *items.Item, options ...*items.ArchiveOptions) (err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "item": item, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Archive.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Event(items.EventItemArchive), + logzap.Object(item), + ) err = m.next.Archive(ctx, item, options...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), + if err != nil { + logger.Error("Failed to archive", zap.Error(err), logzap.Channels(logzap.Userlog, logzap.Syslog)) + return } - for k, v := range map[string]interface{}{ - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Archive.Response", fields...) - + logger.Info("Successfully archived", logzap.Channels(logzap.Userlog)) return err } func (m *loggingMiddleware) Create(ctx context.Context, item *items.Item, opts ...*items.CreateOptions) (created *items.Item, err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "item": item, - "opts": opts} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Create.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Event(items.EventItemCreate), + ) created, err = m.next.Create(ctx, item, opts...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), - } - - for k, v := range map[string]interface{}{ - "created": created, - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) + if err != nil { + logger.Error("Failed to create", zap.Error(err), logzap.Channels(logzap.Userlog, logzap.Syslog), logzap.Object(item)) + return } - m.logger.Debug("Create.Response", fields...) - + logger.Info("Successfully created", logzap.Channels(logzap.Userlog), logzap.Object(created)) return created, err } func (m *loggingMiddleware) Delete(ctx context.Context, item *items.Item, options ...*items.DeleteOptions) (err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "item": item, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Delete.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Event(items.EventItemDelete), + logzap.Object(item), + ) err = m.next.Delete(ctx, item, options...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), + if err != nil { + logger.Error("Failed to delete", zap.Error(err), logzap.Channels(logzap.Userlog, logzap.Syslog)) + return } - for k, v := range map[string]interface{}{ - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Delete.Response", fields...) - + logger.Info("Successfully deleted", logzap.Channels(logzap.Userlog)) return err } func (m *loggingMiddleware) Find(ctx context.Context, spaceId string, envId string, collectionId string, filter *items.Filter, options ...*items.FindOptions) (items []*items.Item, total int, err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "spaceId": spaceId, - "envId": envId, - "collectionId": collectionId, - "filter": filter, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Find.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + ) items, total, err = m.next.Find(ctx, spaceId, envId, collectionId, filter, options...) - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), - } - - for k, v := range map[string]interface{}{ - "items": items, - "total": total, - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) + if err != nil { + logger.Error("Failed to find", zap.Error(err)) + return } - m.logger.Debug("Find.Response", fields...) - return items, total, err } func (m *loggingMiddleware) FindArchived(ctx context.Context, spaceId string, envId string, collectionId string, filter *items.Filter, options ...*items.FindArchivedOptions) (items []*items.Item, total int, err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "spaceId": spaceId, - "envId": envId, - "collectionId": collectionId, - "filter": filter, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("FindArchived.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + ) items, total, err = m.next.FindArchived(ctx, spaceId, envId, collectionId, filter, options...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), - } - - for k, v := range map[string]interface{}{ - "items": items, - "total": total, - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) + if err != nil { + logger.Error("Failed to find_archived", zap.Error(err)) + return } - m.logger.Debug("FindArchived.Response", fields...) - return items, total, err } func (m *loggingMiddleware) FindPublished(ctx context.Context, spaceId string, envId string, collectionId string, filter *items.Filter, options ...*items.FindPublishedOptions) (items []*items.Item, total int, err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "spaceId": spaceId, - "envId": envId, - "collectionId": collectionId, - "filter": filter, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("FindPublished.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + ) items, total, err = m.next.FindPublished(ctx, spaceId, envId, collectionId, filter, options...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), - } - - for k, v := range map[string]interface{}{ - "items": items, - "total": total, - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) + if err != nil { + logger.Error("Failed to findpublished", zap.Error(err)) + return } - m.logger.Debug("FindPublished.Response", fields...) - return items, total, err } func (m *loggingMiddleware) Get(ctx context.Context, spaceId string, envId string, collectionId string, itemId string, options ...*items.GetOptions) (item *items.Item, err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "spaceId": spaceId, - "envId": envId, - "collectionId": collectionId, - "itemId": itemId, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Get.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Object(id.NewItemId(spaceId, envId, collectionId, itemId)), + ) item, err = m.next.Get(ctx, spaceId, envId, collectionId, itemId, options...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), + if err != nil { + logger.Error("Failed to get", zap.Error(err)) + return } - for k, v := range map[string]interface{}{ - "item": item, - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Get.Response", fields...) - return item, err } func (m *loggingMiddleware) GetPublished(ctx context.Context, spaceId string, envId string, collectionId string, itemId string, options ...*items.GetPublishedOptions) (item *items.Item, err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "spaceId": spaceId, - "envId": envId, - "collectionId": collectionId, - "itemId": itemId, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("GetPublished.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Object(id.NewItemId(spaceId, envId, collectionId, itemId)), + ) item, err = m.next.GetPublished(ctx, spaceId, envId, collectionId, itemId, options...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), + if err != nil { + logger.Error("Failed to get published", zap.Error(err)) + return } - for k, v := range map[string]interface{}{ - "item": item, - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("GetPublished.Response", fields...) - return item, err } func (m *loggingMiddleware) GetRevision(ctx context.Context, spaceId string, envId string, collectionId string, itemId string, revisionId string, options ...*items.GetRevisionOptions) (item *items.Item, err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "spaceId": spaceId, - "envId": envId, - "collectionId": collectionId, - "itemId": itemId, - "revisionId": revisionId, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("GetRevision.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Object(id.NewItemId(spaceId, envId, collectionId, itemId)), + ) item, err = m.next.GetRevision(ctx, spaceId, envId, collectionId, itemId, revisionId, options...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), + if err != nil { + logger.Error("Failed to get revision", zap.Error(err)) + return } - for k, v := range map[string]interface{}{ - "item": item, - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("GetRevision.Response", fields...) - return item, err } func (m *loggingMiddleware) Introspect(ctx context.Context, item *items.Item, opts ...*items.IntrospectOptions) (itm *items.Item, sch *schema.Schema, err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "item": item, - "opts": opts} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Introspect.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Object(item), + ) itm, sch, err = m.next.Introspect(ctx, item, opts...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), - } - - for k, v := range map[string]interface{}{ - "itm": itm, - "sch": sch, - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) + if err != nil { + logger.Error("Failed to introspect", zap.Error(err)) + return } - m.logger.Debug("Introspect.Response", fields...) - return itm, sch, err } func (m *loggingMiddleware) ListRevisions(ctx context.Context, spaceId string, envId string, collectionId string, itemId string, options ...*items.ListRevisionsOptions) (items []*items.Item, err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "spaceId": spaceId, - "envId": envId, - "collectionId": collectionId, - "itemId": itemId, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("ListRevisions.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Object(id.NewItemId(spaceId, envId, collectionId, itemId)), + ) items, err = m.next.ListRevisions(ctx, spaceId, envId, collectionId, itemId, options...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), + if err != nil { + logger.Error("Failed to list revisions", zap.Error(err)) + return } - for k, v := range map[string]interface{}{ - "items": items, - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("ListRevisions.Response", fields...) - return items, err } func (m *loggingMiddleware) Publish(ctx context.Context, item *items.Item, options ...*items.PublishOptions) (err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "item": item, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Publish.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Event(items.EventItemPublish), + logzap.Object(item), + ) err = m.next.Publish(ctx, item, options...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), + if err != nil { + logger.Error("Failed to publish", zap.Error(err), logzap.Channels(logzap.Userlog, logzap.Syslog)) + return } - for k, v := range map[string]interface{}{ - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Publish.Response", fields...) - + logger.Info("Successfully published", logzap.Channels(logzap.Userlog)) return err } func (m *loggingMiddleware) Unarchive(ctx context.Context, item *items.Item, options ...*items.UnarchiveOptions) (err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "item": item, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Unarchive.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Event(items.EventItemUnarchive), + logzap.Object(item), + ) err = m.next.Unarchive(ctx, item, options...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), - } - - for k, v := range map[string]interface{}{ - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) + if err != nil { + logger.Error("Failed to unarchive", zap.Error(err), logzap.Channels(logzap.Userlog, logzap.Syslog)) + return } - m.logger.Debug("Unarchive.Response", fields...) - + logger.Info("Successfully unarchived", logzap.Channels(logzap.Userlog)) return err } func (m *loggingMiddleware) Undelete(ctx context.Context, item *items.Item, options ...*items.UndeleteOptions) (err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "item": item, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Undelete.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Event(items.EventItemUndelete), + logzap.Object(item), + ) err = m.next.Undelete(ctx, item, options...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), - } - - for k, v := range map[string]interface{}{ - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) + if err != nil { + logger.Error("Failed to undelete", zap.Error(err), logzap.Channels(logzap.Userlog, logzap.Syslog)) + return } - m.logger.Debug("Undelete.Response", fields...) - + logger.Info("Successfully undeleted", logzap.Channels(logzap.Userlog)) return err } func (m *loggingMiddleware) Unpublish(ctx context.Context, item *items.Item, options ...*items.UnpublishOptions) (err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "item": item, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Unpublish.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Event(items.EventItemUnpublish), + logzap.Object(item), + ) err = m.next.Unpublish(ctx, item, options...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), - } - - for k, v := range map[string]interface{}{ - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) + if err != nil { + logger.Error("Failed to unpublish", zap.Error(err), logzap.Channels(logzap.Userlog, logzap.Syslog)) + return } - m.logger.Debug("Unpublish.Response", fields...) - + logger.Info("Successfully unpublished", logzap.Channels(logzap.Userlog)) return err } func (m *loggingMiddleware) Update(ctx context.Context, item *items.Item, options ...*items.UpdateOptions) (err error) { - begin := time.Now() - var fields []zapcore.Field - for k, v := range map[string]interface{}{ - "ctx": ctx, - "item": item, - "options": options} { - if k == "ctx" { - fields = append(fields, zap.String("principal", fmt.Sprint(auth.GetPrincipal(ctx)))) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Update.Request", fields...) + logger := m.logger.With( + logzap.CallerFromContext(ctx), + logzap.Event(items.EventItemUpdate), + logzap.Object(item), + ) err = m.next.Update(ctx, item, options...) - - fields = []zapcore.Field{ - zap.Duration("time", time.Since(begin)), + if err != nil { + logger.Error("Failed to update", zap.Error(err), logzap.Channels(logzap.Userlog, logzap.Syslog)) + return } - for k, v := range map[string]interface{}{ - "err": err} { - if k == "err" { - err, _ := v.(error) - fields = append(fields, zap.Error(err)) - continue - } - fields = append(fields, zap.Reflect(k, v)) - } - - m.logger.Debug("Update.Response", fields...) - + logger.Info("Successfully updated", logzap.Channels(logzap.Userlog)) return err } diff --git a/pkg/items/middleware/middleware.go b/pkg/items/middleware/middleware.go index 70a642a24c7e4ded173bbff5d21711e5d0b81afa..2ce07ef94ff532af1ed3353ef5bdba6e5f6871aa 100644 --- a/pkg/items/middleware/middleware.go +++ b/pkg/items/middleware/middleware.go @@ -13,21 +13,15 @@ import ( type Middleware func(items.Items) items.Items -func WithLog(s items.Items, logger, svcLogger *zap.Logger, log_access bool) items.Items { +func WithLog(s items.Items, logger *zap.Logger, log_access bool) items.Items { if logger == nil { logger = zap.NewNop() } logger = logger.Named("Items") - - if svcLogger == nil { - svcLogger = zap.NewNop() - } - s = LogInfoMiddleware(svcLogger)(s) - - s = ErrorLoggingMiddleware(logger)(s) if log_access { - s = LoggingMiddleware(logger)(s) + s = AccessLoggingMiddleware(logger)(s) } + s = LoggingMiddleware(logger)(s) s = RecoveringMiddleware(logger)(s) return s } diff --git a/zap/channels.go b/zap/channels.go index 21467d40b16e43981e251f2b1d16cab2f68c5d1f..3664f6ad8962e35a98b01acf6a5b54101b716194 100644 --- a/zap/channels.go +++ b/zap/channels.go @@ -9,6 +9,10 @@ import ( const ( channelKey = "channel" + + Syslog = "syslog" + Userlog = "userlog" + // ChannelsAll = "*" ) func ContainsChannels(channels ...string) FilterFunc { diff --git a/zap/field.go b/zap/field.go index 4a7f3c487ae2d0829530826a88d7dc2ac2019e36..a0c56f71083b6981f6c725f11466b4e0d82c789e 100644 --- a/zap/field.go +++ b/zap/field.go @@ -29,13 +29,15 @@ func Event(event string) zap.Field { // Object возвращает поле Рё устанавливает передаваемый аргумент РІ качестве идентификатора объекта РІ формате ObjectId. // Поддерживает типы РІ формате ObjectId: id.Descriptor, string, map[string]any, системные объекты. func Object(v any) zap.Field { - return zap.Reflect("object", id.MustObjectId(v)) + oid, _ := id.NewObjectId(v) + return zap.Reflect("object", oid) } // Caller возвращает поле Рё устанавливает передаваемый аргумент РІ качестве "вызывающего" РІ формате ObjectId. // Поддерживает типы РІ формате ObjectId: id.Descriptor, string, map[string]any, системные объекты. func Caller(v any) zap.Field { - return zap.Reflect("caller", id.MustObjectId(v)) + oid, _ := id.NewObjectId(v) + return zap.Reflect("caller", oid) } // CallerFromContext извлекает auth.Principal РёР· контекста Рё устанавливает его РІ качестве "вызывающего" РІ формате Object.