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