{"id":405189,"date":"2024-06-29T18:10:24","date_gmt":"2024-06-29T18:10:24","guid":{"rendered":"http:\/\/savepearlharbor.com\/?p=405189"},"modified":"-0001-11-30T00:00:00","modified_gmt":"-0001-11-29T21:00:00","slug":"","status":"publish","type":"post","link":"https:\/\/savepearlharbor.com\/?p=405189","title":{"rendered":"Notes about OpenTracing and Logs<\/span>"},"content":{"rendered":"
<\/div>\n
\n
\n
\n
\n

1)<\/strong>\u00a0OpenTracing (OT)<\/u>\u00a0!=<\/strong>\u00a0Logs<\/u>\u00a0but they are very similar.<\/p>\n

2)<\/strong>\u00a0Every application has 2 types of scopes: ApplicationScope (AScope) and RequestScope (RScope).<\/p>\n

<\/figcaption><\/figure>\n

ApplicationScope<\/u>\u00a0is everything about configs and\u00a0DI.<\/p>\n

Think about it as a singleton. This is the thing that starts, does some work, and stops.<\/p>\n

RequestScope<\/u>\u00a0is everything about user request \/ amqp request \/ etc..<\/p>\n

It starts when the application receives\u00a0a request from a client. It encapsulates an execution context.<\/p>\n

3)<\/strong>\u00a0What is the difference between\u00a0OpenTracing<\/u>\u00a0and\u00a0Logs<\/u>?<\/p>\n

Logs are about\u00a0AScope<\/u>\u00a0and OpenTracing is about\u00a0RScope<\/u>.<\/strong><\/p>\n

4)<\/strong>\u00a0Your real application can have more then one\u00a0AScope<\/u>\u00a0at the same time (for example if you are using graceful reload — create new\/destroy old), but usually, only one\u00a0AScope<\/u>\u00a0exists.<\/p>\n

5)\u00a0<\/strong>Logs and OT use the same approach for the messages. This approach called\u00a0structured logging<\/u>.<\/p>\n

This approach is very easy. There is only one important thing.\u00a0Your log message must\u00a0not<\/u>\u00a0contain variable params.\u00a0<\/strong><\/p>\n

6)\u00a0<\/strong>Real application has different layers.\u00a0<\/p>\n

PrimaryAdapter\u00a0\u2192\u00a0UseCase\u00a0\u2192 DomainService\u00a0\u2192 DAO<\/strong>\u00a0\u2192 Client (Secondary Adapter) \u2192 ExternalResource<\/p>\n

The central part of this chain usually builds by DI.<\/p>\n

For example:<\/p>\n

type CService struct {}  func NewCService(..., logger logger.ILogger) *CService {}<\/code><\/pre>\n
And as you can see above Logger is an AScope object, because it should be created when we build our DI-container.<\/p>\n
7)\u00a0Logger is a global object. We should not create a new logger on every request and store it into ctx.<\/strong><\/p>\n
8)<\/strong>\u00a0We should pass context everywhere.<\/strong><\/p>\n
Context is the thing that contains our RScope. (function arguments contain request scope too — because they change between requests)<\/p>\n
OpenTracing widely uses context. (https:\/\/github.com\/opentracing\/opentracing-go#creating-a-span-given-an-existing-go-contextcontext<\/a>)<\/p>\n
So if you do not pass context — you do not have OpenTracing.<\/p>\n
9)<\/strong>\u00a0Small piece of code.<\/p>\n
\/pkg\/logger\/interface.go<\/strong><\/p>\n
\/\/ ==== FIELD ==== type Field struct {    Key   string    Value interface{} }  func F(key string, value interface{}) Field {    return Field{Key: key, Value: value} }  \/\/ func FError - returns field based on error  \/\/ ==== LOGGER ==== type Logger interface {    WithFields(with ...Field) Logger     Debug(ctx context.Context, msg string, with ...Field)    Info(ctx context.Context, msg string, with ...Field)    Warn(ctx context.Context, msg string, with ...Field)    Error(ctx context.Context, msg string, with ...Field) }<\/code><\/pre>\n
\/pkg\/logger\/context.go<\/strong><\/p>\n
type key int  var loggerKey key  func NewContextWithFields(ctx context.Context, with ...Field) context.Context {        fields := make([]Field, 0)    fields = append(fields, fetchFieldsFromContext(ctx)...)    fields = append(fields, with...)     return context.WithValue(ctx, loggerKey, fields) }  func fetchFieldsFromContext(ctx context.Context) []Field {    if fields, ok := ctx.Value(loggerKey).([]Field); ok {       return fields    }     return nil }<\/code><\/pre>\n
\/example.go<\/strong><\/p>\n
func (uc *UseCase) SomeOperation(ctx context.Context, param uint64) {    span, ctx := opentracing.StartSpanFromContext(ctx, \"operation_name\")    defer span.Finish()      uc.logger.Info(ctx, \"Starting domain operation\", logger.F(\"param\", param))    if err := uc.domainSvc.SomeOperation(ctx, param); err != nil {       uc.logger.Error(ctx, \"Unable to perform domain operation\", logger.FError(err))       return    }    uc.logger.Info(ctx, \"Domain operation finished\") }<\/code><\/pre>\n
As you can see above Logger receives the context as the first argument.<\/p>\n
Why? — Because inside of Logger implementation we can define either we need to send this message to OpenTracing collector (if ctx contains span) or just to stdout. (backward compatibility)<\/p>\n
10)<\/strong>\u00a0One more thing. We need to process our errors only one time. SO if we return an error we need\u00a0only<\/u>\u00a0return it. We should not log it inside the same function.<\/p>\n<\/div>\n<\/div>\n<\/div>\n
<\/div>\n

 \u0441\u0441\u044b\u043b\u043a\u0430 \u043d\u0430 \u043e\u0440\u0438\u0433\u0438\u043d\u0430\u043b \u0441\u0442\u0430\u0442\u044c\u0438  https:\/\/habr.com\/ru\/articles\/675010\/<\/a><\/p>\n","protected":false},"excerpt":{"rendered":"
<\/div>\n
\n
\n
\n
\n
1)<\/strong>\u00a0OpenTracing (OT)<\/u>\u00a0!=<\/strong>\u00a0Logs<\/u>\u00a0but they are very similar.<\/p>\n
2)<\/strong>\u00a0Every application has 2 types of scopes: ApplicationScope (AScope) and RequestScope (RScope).<\/p>\n
<\/figcaption><\/figure>\n
ApplicationScope<\/u>\u00a0is everything about configs and\u00a0DI.<\/p>\n
Think about it as a singleton. This is the thing that starts, does some work, and stops.<\/p>\n
RequestScope<\/u>\u00a0is everything about user request \/ amqp request \/ etc..<\/p>\n
It starts when the application receives\u00a0a request from a client. It encapsulates an execution context.<\/p>\n
3)<\/strong>\u00a0What is the difference between\u00a0OpenTracing<\/u>\u00a0and\u00a0Logs<\/u>?<\/p>\n
Logs are about\u00a0AScope<\/u>\u00a0and OpenTracing is about\u00a0RScope<\/u>.<\/strong><\/p>\n
4)<\/strong>\u00a0Your real application can have more then one\u00a0AScope<\/u>\u00a0at the same time (for example if you are using graceful reload — create new\/destroy old), but usually, only one\u00a0AScope<\/u>\u00a0exists.<\/p>\n
5)\u00a0<\/strong>Logs and OT use the same approach for the messages. This approach called\u00a0structured logging<\/u>.<\/p>\n
This approach is very easy. There is only one important thing.\u00a0Your log message must\u00a0not<\/u>\u00a0contain variable params.\u00a0<\/strong><\/p>\n
6)\u00a0<\/strong>Real application has different layers.\u00a0<\/p>\n
PrimaryAdapter\u00a0\u2192\u00a0UseCase\u00a0\u2192 DomainService\u00a0\u2192 DAO<\/strong>\u00a0\u2192 Client (Secondary Adapter) \u2192 ExternalResource<\/p>\n
The central part of this chain usually builds by DI.<\/p>\n
For example:<\/p>\n
type CService struct {}  func NewCService(..., logger logger.ILogger) *CService {}<\/code><\/pre>\n
And as you can see above Logger is an AScope object, because it should be created when we build our DI-container.<\/p>\n
7)\u00a0Logger is a global object. We should not create a new logger on every request and store it into ctx.<\/strong><\/p>\n
8)<\/strong>\u00a0We should pass context everywhere.<\/strong><\/p>\n
Context is the thing that contains our RScope. (function arguments contain request scope too — because they change between requests)<\/p>\n
OpenTracing widely uses context. (https:\/\/github.com\/opentracing\/opentracing-go#creating-a-span-given-an-existing-go-contextcontext<\/a>)<\/p>\n
So if you do not pass context — you do not have OpenTracing.<\/p>\n
9)<\/strong>\u00a0Small piece of code.<\/p>\n
\/pkg\/logger\/interface.go<\/strong><\/p>\n
\/\/ ==== FIELD ==== type Field struct {    Key   string    Value interface{} }  func F(key string, value interface{}) Field {    return Field{Key: key, Value: value} }  \/\/ func FError - returns field based on error  \/\/ ==== LOGGER ==== type Logger interface {    WithFields(with ...Field) Logger     Debug(ctx context.Context, msg string, with ...Field)    Info(ctx context.Context, msg string, with ...Field)    Warn(ctx context.Context, msg string, with ...Field)    Error(ctx context.Context, msg string, with ...Field) }<\/code><\/pre>\n
\/pkg\/logger\/context.go<\/strong><\/p>\n
type key int  var loggerKey key  func NewContextWithFields(ctx context.Context, with ...Field) context.Context {        fields := make([]Field, 0)    fields = append(fields, fetchFieldsFromContext(ctx)...)    fields = append(fields, with...)     return context.WithValue(ctx, loggerKey, fields) }  func fetchFieldsFromContext(ctx context.Context) []Field {    if fields, ok := ctx.Value(loggerKey).([]Field); ok {       return fields    }     return nil }<\/code><\/pre>\n
\/example.go<\/strong><\/p>\n
func (uc *UseCase) SomeOperation(ctx context.Context, param uint64) {    span, ctx := opentracing.StartSpanFromContext(ctx, \"operation_name\")    defer span.Finish()      uc.logger.Info(ctx, \"Starting domain operation\", logger.F(\"param\", param))    if err := uc.domainSvc.SomeOperation(ctx, param); err != nil {       uc.logger.Error(ctx, \"Unable to perform domain operation\", logger.FError(err))       return    }    uc.logger.Info(ctx, \"Domain operation finished\") }<\/code><\/pre>\n
As you can see above Logger receives the context as the first argument.<\/p>\n
Why? — Because inside of Logger implementation we can define either we need to send this message to OpenTracing collector (if ctx contains span) or just to stdout. (backward compatibility)<\/p>\n
10)<\/strong>\u00a0One more thing. We need to process our errors only one time. SO if we return an error we need\u00a0only<\/u>\u00a0return it. We should not log it inside the same function.<\/p>\n<\/div>\n<\/div>\n<\/div>\n
<\/div>\n

 \u0441\u0441\u044b\u043b\u043a\u0430 \u043d\u0430 \u043e\u0440\u0438\u0433\u0438\u043d\u0430\u043b \u0441\u0442\u0430\u0442\u044c\u0438  https:\/\/habr.com\/ru\/articles\/675010\/<\/a>
<\/br><\/br><\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[],"tags":[],"class_list":["post-405189","post","type-post","status-publish","format-standard","hentry"],"_links":{"self":[{"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=\/wp\/v2\/posts\/405189","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=%2Fwp%2Fv2%2Fcomments&post=405189"}],"version-history":[{"count":0,"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=\/wp\/v2\/posts\/405189\/revisions"}],"wp:attachment":[{"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=%2Fwp%2Fv2%2Fmedia&parent=405189"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=%2Fwp%2Fv2%2Fcategories&post=405189"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=%2Fwp%2Fv2%2Ftags&post=405189"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}