github.com/matrixorigin/matrixone@v0.7.0/pkg/util/trace/impl/motrace/example/main.go (about)

     1  // Copyright 2022 Matrix Origin
     2  //
     3  // Licensed under the Apache License, Version 2.0 (the "License");
     4  // you may not use this file except in compliance with the License.
     5  // You may obtain a copy of the License at
     6  //
     7  //      http://www.apache.org/licenses/LICENSE-2.0
     8  //
     9  // Unless required by applicable law or agreed to in writing, software
    10  // distributed under the License is distributed on an "AS IS" BASIS,
    11  // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
    12  // See the License for the specific language governing permissions and
    13  // limitations under the License.
    14  
    15  package main
    16  
    17  import (
    18  	"context"
    19  	goErrors "errors"
    20  	"fmt"
    21  	"github.com/matrixorigin/matrixone/pkg/config"
    22  	"github.com/matrixorigin/matrixone/pkg/util/export/table"
    23  	"time"
    24  
    25  	"github.com/lni/dragonboat/v4/logger"
    26  	"github.com/matrixorigin/matrixone/pkg/logutil"
    27  	"github.com/matrixorigin/matrixone/pkg/util/errutil"
    28  	ie "github.com/matrixorigin/matrixone/pkg/util/internalExecutor"
    29  	"github.com/matrixorigin/matrixone/pkg/util/trace"
    30  	"github.com/matrixorigin/matrixone/pkg/util/trace/impl/motrace"
    31  	"go.uber.org/zap"
    32  )
    33  
    34  var _ ie.InternalExecutor = &logOutputExecutor{}
    35  
    36  type logOutputExecutor struct{}
    37  
    38  func (l logOutputExecutor) Exec(ctx context.Context, s string, s2 ie.SessionOverrideOptions) error {
    39  	logutil.Info(s)
    40  	return nil
    41  }
    42  func (l logOutputExecutor) Query(ctx context.Context, s string, _ ie.SessionOverrideOptions) ie.InternalExecResult {
    43  	logutil.Info(s)
    44  	return nil
    45  }
    46  func (l logOutputExecutor) ApplySessionOverride(ie.SessionOverrideOptions) {}
    47  
    48  type dummyStringWriter struct{}
    49  
    50  func (w *dummyStringWriter) WriteString(s string) (n int, err error) {
    51  	return fmt.Printf("dummyStringWriter: %s\n", s)
    52  }
    53  func (w *dummyStringWriter) WriteRow(row *table.Row) error {
    54  	fmt.Printf("dummyStringWriter: %v\n", row.ToStrings())
    55  	return nil
    56  }
    57  func (w *dummyStringWriter) GetContent() string          { return "" }
    58  func (w *dummyStringWriter) FlushAndClose() (int, error) { return 0, nil }
    59  
    60  var dummyFSWriterFactory = func(context.Context, string, *table.Table, time.Time) table.RowWriter {
    61  	return &dummyStringWriter{}
    62  }
    63  
    64  func bootstrap(ctx context.Context) error {
    65  	logutil.SetupMOLogger(&logutil.LogConfig{Format: "console", DisableStore: false})
    66  	SV := config.ObservabilityParameters{}
    67  	SV.SetDefaultValues("v0.6.0")
    68  	// init trace/log/error framework & BatchProcessor
    69  	return motrace.InitWithConfig(ctx,
    70  		&SV,
    71  		// nodeType like CN/DN/LogService; id maybe in config.
    72  		motrace.WithNode("node_uuid", trace.NodeTypeStandalone),
    73  		// WithFSWriterFactory for config[traceBatchProcessor] = "FileService"
    74  		motrace.WithFSWriterFactory(dummyFSWriterFactory),
    75  		// WithSQLExecutor for config[traceBatchProcessor] = "InternalExecutor"
    76  		motrace.WithSQLExecutor(func() ie.InternalExecutor {
    77  			return &logOutputExecutor{}
    78  		}),
    79  	)
    80  
    81  }
    82  
    83  func traceUsage(ctx context.Context) {
    84  	// Case 1: start new span, which calculate duration of function traceUsage()
    85  	newCtx, span1 := trace.Start(ctx, "traceUsage")
    86  	// calling End() will calculate running duration(us)
    87  	defer span1.End()
    88  	logutil.Info("1st span with TraceId & SpanID", trace.SpanField(span1.SpanContext()))
    89  
    90  	// case 2: calling another function, please pass newCtx
    91  	traceUsageDepth_1(newCtx)
    92  	// case 4: calling again, will have new span
    93  	traceUsageDepth_1(newCtx)
    94  
    95  	// case 5: new span with same parent of span_1, you should use in-args ctx
    96  	// span2 will be brother with span1
    97  	newCtx2, span2 := trace.Start(ctx, "traceUsage_2")
    98  	traceUsageDepth_1_1(newCtx2)
    99  	span2.End()
   100  }
   101  
   102  func traceUsageDepth_1(ctx context.Context) {
   103  	// case 3: start new spanChild using ctx in-args,
   104  	// spanChild like a children of span1
   105  	depth1Ctx, spanChild := trace.Start(ctx, "traceUsage")
   106  	defer spanChild.End()
   107  	logutil.Info("2rd spanChild has same TraceId & new SpanID", trace.SpanField(spanChild.SpanContext()))
   108  	logutil.Info("ctx contain the spanChild info", trace.ContextField(depth1Ctx))
   109  	logutil.Infof("2rd spanChild has parent spanChild info, like parent span_id: %d", spanChild.ParentSpanContext().SpanID)
   110  }
   111  
   112  func traceUsageDepth_1_1(ctx context.Context) {
   113  	logutil.Info("traceUsageDepth_1_1 working")
   114  }
   115  
   116  func logUsage(ctx context.Context) {
   117  	// case 1: use logutil.Info/Infof/..., without context.Context
   118  	// it will store log into db, related to Node
   119  	logutil.Info("use without ctx")
   120  
   121  	// case 2: use logutil.Info/Infof/..., with context.Context
   122  	// it will store log into db, related to span, which save in ctx
   123  	// Suggestion: trace.ContextField should be 1st Field arg, which will help log to find span info faster.
   124  	logutil.Info("use with ctx", trace.ContextField(ctx), zap.Int("int", 1))
   125  
   126  	// case 3: use logutil2.Info/Infof/..., with contex.Context
   127  	// it will store log into db, related to span, which save in ctx
   128  	// (removed)
   129  
   130  	// case4: 3rd lib like dragonboat, could use logutil.DragonboatFactory, like
   131  	//logger.SetLoggerFactory(logutil.DragonboatFactory)
   132  	plog := logger.GetLogger("dragonboat.logger")
   133  	plog.Infof("log with DragonboatFactory, now: %s", time.Now())
   134  }
   135  
   136  func outputError(msg string, err error) {
   137  	logutil.Infof("%s %%s: %s", msg, err)
   138  	logutil.Infof("%s %%+s: %+s", msg, err)
   139  	logutil.Infof("%s %%v: %v", msg, err)
   140  	logutil.Infof("%s %%+v: %+v", msg, err)
   141  	logutil.Infof("%s Error(): %v", msg, err.Error()) // just like raw error
   142  	logutil.Info("---")
   143  }
   144  
   145  func errorUsage(ctx context.Context) {
   146  	newCtx, span := trace.Start(ctx, "errorUsage")
   147  	defer span.End()
   148  
   149  	base := goErrors.New("base error")
   150  	logutil.Infof("base err: %v", base)
   151  
   152  	// case 1: WithMessage
   153  	// removed
   154  
   155  	// case 2: WithStack
   156  	// removed
   157  
   158  	// case 3: WithContext, store db & log
   159  	logutil.Info("WithContext with default action: 1) store in db; 2) gen log")
   160  	outputError("WithContext", errutil.WithContext(newCtx, base))
   161  	outputError("Wrapf", errutil.Wrapf(base, "extra message"))
   162  
   163  	// case 4: NewWithContext, store db & log
   164  	// removed
   165  
   166  	// case 5: ContextWithNoReport
   167  	noReportCtx := errutil.ContextWithNoReport(newCtx, true)
   168  	errutil.ReportError(noReportCtx, base)
   169  
   170  }
   171  
   172  type FunctionRequest struct {
   173  	trace.SpanContext
   174  }
   175  
   176  type rpcRequest struct {
   177  	message []byte
   178  }
   179  
   180  func rpcUsage(ctx context.Context) {
   181  	ctx, span := trace.Start(ctx, "rpcUsage", trace.WithNewRoot(true))
   182  	defer span.End()
   183  	req := &FunctionRequest{
   184  		SpanContext: trace.SpanFromContext(ctx).SpanContext(),
   185  	}
   186  	logutil.Info("client call Function", trace.ContextField(ctx))
   187  
   188  	// serialize
   189  	rpcReq := &rpcRequest{message: make([]byte, 24)}
   190  	if _, err := req.SpanContext.MarshalTo(rpcReq.message); err != nil {
   191  		logutil.Errorf("callFunction: %v", err)
   192  		panic(err)
   193  	}
   194  	logutil.Infof("message: %x", rpcReq.message)
   195  
   196  	// deserialize
   197  	var sc trace.SpanContext
   198  	if err := sc.Unmarshal(rpcReq.message); err != nil {
   199  		panic(err)
   200  	}
   201  	svrRootCtx := trace.ContextWithSpanContext(ctx, sc)
   202  	logutil.Info("server accept request", trace.ContextField(svrRootCtx))
   203  	newCtx2, span2 := trace.Start(svrRootCtx, "Function")
   204  	defer span2.End()
   205  
   206  	logutil.Info("server do Function, have same TraceId from client.", trace.ContextField(newCtx2))
   207  }
   208  
   209  func mixUsage(ctx context.Context) {
   210  	newCtx, span := trace.Start(ctx, "mixUsage")
   211  	defer span.End()
   212  
   213  	logutil.Info("message", trace.ContextField(newCtx))
   214  
   215  	err := childFunc(newCtx)
   216  	motrace.ReportError(newCtx, errutil.Wrapf(err, "extra %s", "message"), 0)
   217  	logutil.Warnf("ReportError with NoReport: '%v'", err)
   218  	noReportCtx := errutil.ContextWithNoReport(newCtx, true)
   219  	motrace.ReportError(noReportCtx, err, 0)
   220  	logutil.Warnf("ReportError with NoReport, Done.")
   221  
   222  }
   223  
   224  func childFunc(ctx context.Context) error {
   225  	err := goErrors.New("example: not found Database")
   226  	return errutil.WithContext(ctx, err)
   227  }
   228  
   229  func shutdown(ctx context.Context) {
   230  	logutil.Warn("shutdown", trace.ContextField(ctx))
   231  	motrace.Shutdown(ctx)
   232  }
   233  
   234  func main() {
   235  	ctx := context.Background()
   236  
   237  	// rootCtx should be root Context of Server running, you can get it also by motrace.DefaultContext()
   238  	err := bootstrap(ctx)
   239  	if err != nil {
   240  		panic(err)
   241  	}
   242  	rootCtx := motrace.DefaultContext()
   243  	// show rootCtx in zap.logger format
   244  	logutil.Info("root ctx", trace.ContextField(rootCtx))
   245  	logutil.Info("default ctx", trace.ContextField(motrace.DefaultContext()))
   246  
   247  	traceUsage(rootCtx)
   248  
   249  	logUsage(rootCtx)
   250  
   251  	errorUsage(rootCtx)
   252  
   253  	rpcUsage(rootCtx)
   254  
   255  	mixUsage(rootCtx)
   256  
   257  	logutil.Warn("wait 5s to see insert sql", trace.ContextField(rootCtx))
   258  
   259  	shutdown(rootCtx)
   260  }