[#148] Add trace_id to logs

Signed-off-by: Roman Loginov <r.loginov@yadro.com>
This commit is contained in:
Roman Loginov 2024-10-08 12:08:39 +03:00
parent c8473498ae
commit a044f15e6a
5 changed files with 81 additions and 36 deletions

View file

@ -3,7 +3,10 @@
This document outlines major changes between releases.
## [Unreleased]
### Added
- Support percent-encoding for GET queries (#134)
- Add `trace_id` to logs (##)
### Changed
- Update go version to 1.22 (#132)

View file

@ -41,6 +41,7 @@ import (
"github.com/nspcc-dev/neo-go/pkg/wallet"
"github.com/spf13/viper"
"github.com/valyala/fasthttp"
"go.opentelemetry.io/otel/trace"
"go.uber.org/zap"
"golang.org/x/exp/slices"
)
@ -536,15 +537,15 @@ func (a *app) configureRouter(handler *handler.Handler) {
response.Error(r, "Method Not Allowed", fasthttp.StatusMethodNotAllowed)
}
r.POST("/upload/{cid}", a.logger(a.canonicalizer(a.tokenizer(a.tracer(a.reqNamespace(handler.Upload))))))
r.POST("/upload/{cid}", a.tracer(a.logger(a.canonicalizer(a.tokenizer(a.reqNamespace(handler.Upload))))))
a.log.Info(logs.AddedPathUploadCid)
r.GET("/get/{cid}/{oid:*}", a.logger(a.canonicalizer(a.tokenizer(a.tracer(a.reqNamespace(handler.DownloadByAddressOrBucketName))))))
r.HEAD("/get/{cid}/{oid:*}", a.logger(a.canonicalizer(a.tokenizer(a.tracer(a.reqNamespace(handler.HeadByAddressOrBucketName))))))
r.GET("/get/{cid}/{oid:*}", a.tracer(a.logger(a.canonicalizer(a.tokenizer(a.reqNamespace(handler.DownloadByAddressOrBucketName))))))
r.HEAD("/get/{cid}/{oid:*}", a.tracer(a.logger(a.canonicalizer(a.tokenizer(a.reqNamespace(handler.HeadByAddressOrBucketName))))))
a.log.Info(logs.AddedPathGetCidOid)
r.GET("/get_by_attribute/{cid}/{attr_key}/{attr_val:*}", a.logger(a.canonicalizer(a.tokenizer(a.tracer(a.reqNamespace(handler.DownloadByAttribute))))))
r.HEAD("/get_by_attribute/{cid}/{attr_key}/{attr_val:*}", a.logger(a.canonicalizer(a.tokenizer(a.tracer(a.reqNamespace(handler.HeadByAttribute))))))
r.GET("/get_by_attribute/{cid}/{attr_key}/{attr_val:*}", a.tracer(a.logger(a.canonicalizer(a.tokenizer(a.reqNamespace(handler.DownloadByAttribute))))))
r.HEAD("/get_by_attribute/{cid}/{attr_key}/{attr_val:*}", a.tracer(a.logger(a.canonicalizer(a.tokenizer(a.reqNamespace(handler.HeadByAttribute))))))
a.log.Info(logs.AddedPathGetByAttributeCidAttrKeyAttrVal)
r.GET("/zip/{cid}/{prefix:*}", a.logger(a.canonicalizer(a.tokenizer(a.tracer(a.reqNamespace(handler.DownloadZipped))))))
r.GET("/zip/{cid}/{prefix:*}", a.tracer(a.logger(a.canonicalizer(a.tokenizer(a.reqNamespace(handler.DownloadZipped))))))
a.log.Info(logs.AddedPathZipCidPrefix)
a.webServer.Handler = r.Handler
@ -552,11 +553,20 @@ func (a *app) configureRouter(handler *handler.Handler) {
func (a *app) logger(h fasthttp.RequestHandler) fasthttp.RequestHandler {
return func(req *fasthttp.RequestCtx) {
a.log.Info(logs.Request, zap.String("remote", req.RemoteAddr().String()),
fields := []zap.Field{
zap.String("remote", req.RemoteAddr().String()),
zap.ByteString("method", req.Method()),
zap.ByteString("path", req.Path()),
zap.ByteString("query", req.QueryArgs().QueryString()),
zap.Uint64("id", req.ID()))
zap.Uint64("id", req.ID()),
}
appCtx := utils.GetContextFromRequest(req)
if traceID := trace.SpanFromContext(appCtx).SpanContext().TraceID(); traceID.IsValid() {
fields = append(fields, zap.String("trace_id", traceID.String()))
}
a.log.Info(logs.Request, fields...)
h(req)
}
}
@ -595,9 +605,19 @@ func (a *app) canonicalizer(h fasthttp.RequestHandler) fasthttp.RequestHandler {
func (a *app) tokenizer(h fasthttp.RequestHandler) fasthttp.RequestHandler {
return func(req *fasthttp.RequestCtx) {
appCtx, err := tokens.StoreBearerTokenAppCtx(a.ctx, req)
appCtx, err := tokens.StoreBearerTokenAppCtx(utils.GetContextFromRequest(req), req)
if err != nil {
a.log.Error(logs.CouldNotFetchAndStoreBearerToken, zap.Uint64("id", req.ID()), zap.Error(err))
fields := []zap.Field{
zap.Uint64("id", req.ID()),
zap.Error(err),
}
reqCtx := utils.GetContextFromRequest(req)
if traceID := trace.SpanFromContext(reqCtx).SpanContext().TraceID(); traceID.IsValid() {
fields = append(fields, zap.String("trace_id", traceID.String()))
}
a.log.Error(logs.CouldNotFetchAndStoreBearerToken, fields...)
response.Error(req, "could not fetch and store bearer token: "+err.Error(), fasthttp.StatusBadRequest)
return
}
@ -608,9 +628,7 @@ func (a *app) tokenizer(h fasthttp.RequestHandler) fasthttp.RequestHandler {
func (a *app) tracer(h fasthttp.RequestHandler) fasthttp.RequestHandler {
return func(req *fasthttp.RequestCtx) {
appCtx := utils.GetContextFromRequest(req)
appCtx, span := utils.StartHTTPServerSpan(appCtx, req, "REQUEST")
appCtx, span := utils.StartHTTPServerSpan(a.ctx, req, "REQUEST")
defer func() {
utils.SetHTTPTraceInfo(appCtx, span, req)
span.End()

View file

@ -18,6 +18,7 @@ import (
"git.frostfs.info/TrueCloudLab/frostfs-sdk-go/object"
oid "git.frostfs.info/TrueCloudLab/frostfs-sdk-go/object/id"
"github.com/valyala/fasthttp"
"go.opentelemetry.io/otel/trace"
"go.uber.org/zap"
)
@ -81,19 +82,25 @@ func (h *Handler) addObjectToZip(zw *zip.Writer, obj *object.Object) (io.Writer,
// DownloadZipped handles zip by prefix requests.
func (h *Handler) DownloadZipped(c *fasthttp.RequestCtx) {
scid, _ := c.UserValue("cid").(string)
prefix, _ := c.UserValue("prefix").(string)
var (
scid, _ = c.UserValue("cid").(string)
prefix, _ = c.UserValue("prefix").(string)
log = h.log
ctx = utils.GetContextFromRequest(c)
)
if traceID := trace.SpanFromContext(ctx).SpanContext().TraceID(); traceID.IsValid() {
log = log.With(zap.String("trace_id", traceID.String()))
}
prefix, err := url.QueryUnescape(prefix)
if err != nil {
h.log.Error(logs.FailedToUnescapeQuery, zap.String("cid", scid), zap.String("prefix", prefix), zap.Uint64("id", c.ID()), zap.Error(err))
log.Error(logs.FailedToUnescapeQuery, zap.String("cid", scid), zap.String("prefix", prefix), zap.Uint64("id", c.ID()), zap.Error(err))
response.Error(c, "could not unescape prefix: "+err.Error(), fasthttp.StatusBadRequest)
return
}
log := h.log.With(zap.String("cid", scid), zap.String("prefix", prefix), zap.Uint64("id", c.ID()))
ctx := utils.GetContextFromRequest(c)
log = h.log.With(zap.String("cid", scid), zap.String("prefix", prefix), zap.Uint64("id", c.ID()))
bktInfo, err := h.getBucketInfo(ctx, scid, log)
if err != nil {

View file

@ -23,6 +23,7 @@ import (
oid "git.frostfs.info/TrueCloudLab/frostfs-sdk-go/object/id"
"git.frostfs.info/TrueCloudLab/frostfs-sdk-go/user"
"github.com/valyala/fasthttp"
"go.opentelemetry.io/otel/trace"
"go.uber.org/zap"
)
@ -182,9 +183,12 @@ func (h *Handler) byAddress(c *fasthttp.RequestCtx, f func(context.Context, requ
idCnr, _ = c.UserValue("cid").(string)
idObj, _ = c.UserValue("oid").(string)
log = h.log.With(zap.String("cid", idCnr), zap.String("oid", idObj))
ctx = utils.GetContextFromRequest(c)
)
ctx := utils.GetContextFromRequest(c)
if traceID := trace.SpanFromContext(ctx).SpanContext().TraceID(); traceID.IsValid() {
log = log.With(zap.String("trace_id", traceID.String()))
}
bktInfo, err := h.getBucketInfo(ctx, idCnr, log)
if err != nil {
@ -213,16 +217,19 @@ func (h *Handler) byObjectName(req *fasthttp.RequestCtx, f func(context.Context,
bucketname = req.UserValue("cid").(string)
key = req.UserValue("oid").(string)
log = h.log.With(zap.String("bucketname", bucketname), zap.String("key", key))
ctx = utils.GetContextFromRequest(req)
)
if traceID := trace.SpanFromContext(ctx).SpanContext().TraceID(); traceID.IsValid() {
log = log.With(zap.String("trace_id", traceID.String()))
}
unescapedKey, err := url.QueryUnescape(key)
if err != nil {
logAndSendBucketError(req, log, err)
return
}
ctx := utils.GetContextFromRequest(req)
bktInfo, err := h.getBucketInfo(ctx, bucketname, log)
if err != nil {
logAndSendBucketError(req, log, err)
@ -255,27 +262,33 @@ func (h *Handler) byObjectName(req *fasthttp.RequestCtx, f func(context.Context,
// byAttribute is a wrapper similar to byAddress.
func (h *Handler) byAttribute(c *fasthttp.RequestCtx, f func(context.Context, request, oid.Address)) {
scid, _ := c.UserValue("cid").(string)
key, _ := c.UserValue("attr_key").(string)
val, _ := c.UserValue("attr_val").(string)
var (
scid, _ = c.UserValue("cid").(string)
key, _ = c.UserValue("attr_key").(string)
val, _ = c.UserValue("attr_val").(string)
log = h.log
ctx = utils.GetContextFromRequest(c)
)
if traceID := trace.SpanFromContext(ctx).SpanContext().TraceID(); traceID.IsValid() {
log = log.With(zap.String("trace_id", traceID.String()))
}
key, err := url.QueryUnescape(key)
if err != nil {
h.log.Error(logs.FailedToUnescapeQuery, zap.String("cid", scid), zap.String("attr_key", key), zap.Uint64("id", c.ID()), zap.Error(err))
log.Error(logs.FailedToUnescapeQuery, zap.String("cid", scid), zap.String("attr_key", key), zap.Uint64("id", c.ID()), zap.Error(err))
response.Error(c, "could not unescape attr_key: "+err.Error(), fasthttp.StatusBadRequest)
return
}
val, err = url.QueryUnescape(val)
if err != nil {
h.log.Error(logs.FailedToUnescapeQuery, zap.String("cid", scid), zap.String("attr_val", val), zap.Uint64("id", c.ID()), zap.Error(err))
log.Error(logs.FailedToUnescapeQuery, zap.String("cid", scid), zap.String("attr_val", val), zap.Uint64("id", c.ID()), zap.Error(err))
response.Error(c, "could not unescape attr_val: "+err.Error(), fasthttp.StatusBadRequest)
return
}
log := h.log.With(zap.String("cid", scid), zap.String("attr_key", key), zap.String("attr_val", val))
ctx := utils.GetContextFromRequest(c)
log = log.With(zap.String("cid", scid), zap.String("attr_key", key), zap.String("attr_val", val))
bktInfo, err := h.getBucketInfo(ctx, scid, log)
if err != nil {

View file

@ -16,6 +16,7 @@ import (
"git.frostfs.info/TrueCloudLab/frostfs-sdk-go/object"
oid "git.frostfs.info/TrueCloudLab/frostfs-sdk-go/object/id"
"github.com/valyala/fasthttp"
"go.opentelemetry.io/otel/trace"
"go.uber.org/zap"
)
@ -52,9 +53,12 @@ func (h *Handler) Upload(req *fasthttp.RequestCtx) {
log = h.log.With(zap.String("cid", scid))
bodyStream = req.RequestBodyStream()
drainBuf = make([]byte, drainBufSize)
ctx = utils.GetContextFromRequest(req)
)
ctx := utils.GetContextFromRequest(req)
if traceID := trace.SpanFromContext(ctx).SpanContext().TraceID(); traceID.IsValid() {
log = log.With(zap.String("trace_id", traceID.String()))
}
bktInfo, err := h.getBucketInfo(ctx, scid, log)
if err != nil {
@ -76,12 +80,12 @@ func (h *Handler) Upload(req *fasthttp.RequestCtx) {
)
}()
boundary := string(req.Request.Header.MultipartFormBoundary())
if file, err = fetchMultipartFile(h.log, bodyStream, boundary); err != nil {
if file, err = fetchMultipartFile(log, bodyStream, boundary); err != nil {
log.Error(logs.CouldNotReceiveMultipartForm, zap.Error(err))
response.Error(req, "could not receive multipart/form: "+err.Error(), fasthttp.StatusBadRequest)
return
}
filtered, err := filterHeaders(h.log, &req.Request.Header)
filtered, err := filterHeaders(log, &req.Request.Header)
if err != nil {
log.Error(logs.CouldNotProcessHeaders, zap.Error(err))
response.Error(req, err.Error(), fasthttp.StatusBadRequest)
@ -143,7 +147,7 @@ func (h *Handler) Upload(req *fasthttp.RequestCtx) {
}
if idObj, err = h.frostfs.CreateObject(ctx, prm); err != nil {
h.handlePutFrostFSErr(req, err)
h.handlePutFrostFSErr(req, err, log)
return
}
@ -174,11 +178,11 @@ func (h *Handler) Upload(req *fasthttp.RequestCtx) {
req.Response.Header.SetContentType(jsonHeader)
}
func (h *Handler) handlePutFrostFSErr(r *fasthttp.RequestCtx, err error) {
func (h *Handler) handlePutFrostFSErr(r *fasthttp.RequestCtx, err error, log *zap.Logger) {
statusCode, msg, additionalFields := response.FormErrorResponse("could not store file in frostfs", err)
logFields := append([]zap.Field{zap.Error(err)}, additionalFields...)
h.log.Error(logs.CouldNotStoreFileInFrostfs, logFields...)
log.Error(logs.CouldNotStoreFileInFrostfs, logFields...)
response.Error(r, msg, statusCode)
}