vitess.io/vitess@v0.16.2/tools/rowlog/rowlog.go (about) 1 package main 2 3 import ( 4 "context" 5 "encoding/json" 6 "flag" 7 "fmt" 8 "io" 9 "os" 10 "reflect" 11 "strconv" 12 "strings" 13 "sync" 14 "time" 15 16 "github.com/spf13/pflag" 17 18 "vitess.io/vitess/go/mysql" 19 "vitess.io/vitess/go/sqltypes" 20 "vitess.io/vitess/go/vt/binlog/binlogplayer" 21 "vitess.io/vitess/go/vt/discovery" 22 "vitess.io/vitess/go/vt/log" 23 "vitess.io/vitess/go/vt/logutil" 24 "vitess.io/vitess/go/vt/topo" 25 "vitess.io/vitess/go/vt/vtctl/vtctlclient" 26 "vitess.io/vitess/go/vt/vtgate/vtgateconn" 27 28 _ "vitess.io/vitess/go/vt/topo/etcd2topo" // TODO: after #11394, add rowlog to this https://github.com/vitessio/vitess/pull/11394/files#diff-ee3c1b94c587244ea0645a8ee10187e1112167725f752d58cf17bab6e6d1047cR85 29 _ "vitess.io/vitess/go/vt/vtctl/grpcvtctlclient" 30 _ "vitess.io/vitess/go/vt/vtgate/grpcvtgateconn" 31 _ "vitess.io/vitess/go/vt/vttablet/grpctabletconn" 32 33 binlogdatapb "vitess.io/vitess/go/vt/proto/binlogdata" 34 logutilpb "vitess.io/vitess/go/vt/proto/logutil" 35 querypb "vitess.io/vitess/go/vt/proto/query" 36 topodatapb "vitess.io/vitess/go/vt/proto/topodata" 37 vtgatepb "vitess.io/vitess/go/vt/proto/vtgate" 38 ) 39 40 type RowLogConfig struct { 41 ids, cells []string 42 43 sourceKeyspace, targetKeyspace, table, vtgate, vtctld, pk string 44 } 45 46 func (rlc *RowLogConfig) String() string { 47 s := fmt.Sprintf("\tsource:%s, target:%s, table:%s, ids:%s, pk:%s\n", 48 rlc.sourceKeyspace, rlc.targetKeyspace, rlc.table, strings.Join(rlc.ids, ","), rlc.pk) 49 s += fmt.Sprintf("\tvtgate:%s, vtctld:%s, cells:%s", rlc.vtgate, rlc.vtctld, strings.Join(rlc.cells, ",")) 50 return s 51 } 52 53 func (rlc *RowLogConfig) Validate() bool { 54 if rlc.table == "" || len(rlc.cells) == 0 || rlc.vtctld == "" || rlc.vtgate == "" || len(rlc.ids) == 0 || rlc.targetKeyspace == "" || rlc.sourceKeyspace == "" || rlc.pk == "" { 55 return false 56 } 57 return true 58 } 59 60 func usage() { 61 logger := logutil.NewConsoleLogger() 62 pflag.CommandLine.SetOutput(logutil.NewLoggerWriter(logger)) 63 pflag.Usage = func() { 64 logger.Printf("Rowlog Usage:\n") 65 s := "rowlog --ids <id list csv> --table <table_name> --pk <primary_key_only_ints> --source <source_keyspace> --target <target_keyspace> " 66 s += "--vtctld <vtctl url> --vtgate <vtgate url> --cells <cell names csv> --topo_implementation <topo type, eg: etcd2> " 67 s += "--topo_global_server_address <top url> --topo_global_root <topo root dir>\n" 68 logger.Printf(s) 69 } 70 } 71 72 func main() { 73 usage() 74 defer log.Flush() 75 ctx := context.Background() 76 config := parseCommandLine() 77 if !config.Validate() { 78 pflag.Usage() 79 return 80 } 81 log.Infof("Starting rowlogger with config: %s", config) 82 fmt.Printf("Starting rowlogger with\n%v\n", config) 83 ts := topo.Open() 84 sourceTablet := getTablet(ctx, ts, config.cells, config.sourceKeyspace) 85 targetTablet := getTablet(ctx, ts, config.cells, config.targetKeyspace) 86 log.Infof("Using tablets %s and %s to get positions", sourceTablet, targetTablet) 87 88 var wg sync.WaitGroup 89 var stream = func(keyspace, tablet string) { 90 defer wg.Done() 91 var startPos, stopPos string 92 var i int 93 var done, fieldsPrinted bool 94 var err error 95 for { 96 i++ 97 if i > 100 { 98 log.Errorf("returning without completion : Timing out for keyspace %s", keyspace) 99 return 100 } 101 log.Infof("%s Iteration:%d", keyspace, i) 102 startPos, stopPos, done, fieldsPrinted, err = startStreaming(ctx, config.vtgate, config.vtctld, keyspace, tablet, config.table, config.pk, config.ids, startPos, stopPos, fieldsPrinted) 103 if done { 104 log.Infof("Finished streaming all events for keyspace %s", keyspace) 105 fmt.Printf("Finished streaming all events for keyspace %s\n", keyspace) 106 return 107 } 108 if startPos != "" { 109 log.Infof("resuming streaming from %s, error received was %v", startPos, err) 110 } else { 111 log.Errorf("returning without completion of keyspace %s because of error %v", keyspace, err) 112 return 113 } 114 } 115 } 116 117 wg.Add(1) 118 go stream(config.sourceKeyspace, sourceTablet) 119 120 wg.Add(1) 121 go stream(config.targetKeyspace, targetTablet) 122 123 wg.Wait() 124 125 log.Infof("rowlog done streaming from both source and target") 126 fmt.Printf("\n\nRowlog completed\nIf the program worked you should see two log files with the related binlog entries: %s.log and %s.log\n", 127 config.sourceKeyspace, config.targetKeyspace) 128 } 129 130 func startStreaming(ctx context.Context, vtgate, vtctld, keyspace, tablet, table, pk string, ids []string, startPos, stopPos string, fieldsPrinted bool) (string, string, bool, bool, error) { 131 var err error 132 if startPos == "" { 133 flavor := getFlavor(ctx, vtctld, keyspace) 134 if flavor == "" { 135 log.Errorf("Invalid flavor for %s", keyspace) 136 return "", "", false, false, nil 137 } 138 startPos, stopPos, _ = getPositions(ctx, vtctld, tablet) 139 startPos = flavor + "/" + startPos 140 stopPos = flavor + "/" + stopPos 141 } 142 log.Infof("Streaming keyspace %s from %s upto %s", keyspace, startPos, stopPos) 143 fmt.Printf("Streaming keyspace %s from %s upto %s\n", keyspace, startPos, stopPos) 144 vgtid := &binlogdatapb.VGtid{ 145 ShardGtids: []*binlogdatapb.ShardGtid{{ 146 Keyspace: keyspace, 147 Shard: "0", 148 Gtid: startPos, 149 }}, 150 } 151 filter := &binlogdatapb.Filter{ 152 Rules: []*binlogdatapb.Rule{{ 153 Match: table, 154 Filter: "select * from " + table, 155 }}, 156 FieldEventMode: 1, 157 } 158 conn, err := vtgateconn.Dial(ctx, vtgate) 159 if err != nil { 160 log.Fatal(err) 161 } 162 defer conn.Close() 163 reader, _ := conn.VStream(ctx, topodatapb.TabletType_PRIMARY, vgtid, filter, &vtgatepb.VStreamFlags{}) 164 var fields []*querypb.Field 165 var gtid string 166 var plan *TablePlan 167 var lastLoggedAt int64 168 var totalRowsForTable, filteredRows int 169 for { 170 evs, err := reader.Recv() 171 switch err { 172 case nil: 173 for _, ev := range evs { 174 now := time.Now().Unix() 175 if now-lastLoggedAt > 60 && ev.Timestamp != 0 { // every minute 176 lastLoggedAt = now 177 log.Infof("%s Progress: %d/%d rows, %s: %s", keyspace, filteredRows, totalRowsForTable, 178 time.Unix(ev.Timestamp, 0).Format(time.RFC3339), gtid) 179 fmt.Printf(".") 180 } 181 switch ev.Type { 182 case binlogdatapb.VEventType_VGTID: 183 gtid = ev.Vgtid.ShardGtids[0].Gtid 184 case binlogdatapb.VEventType_FIELD: 185 fields = ev.FieldEvent.Fields 186 plan = getTablePlan(keyspace, fields, ev.FieldEvent.TableName, pk, ids) 187 if !fieldsPrinted { 188 outputHeader(plan) 189 fieldsPrinted = true 190 } 191 case binlogdatapb.VEventType_ROW: 192 totalRowsForTable += len(ev.RowEvent.RowChanges) 193 rows := processRowEvent(plan, gtid, ev) 194 if len(rows) > 0 { 195 filteredRows += len(rows) 196 outputRows(plan, rows) 197 } 198 default: 199 } 200 } 201 var err error 202 var currentPosition, stopPosition mysql.Position 203 currentPosition, err = binlogplayer.DecodePosition(gtid) 204 if err != nil { 205 fmt.Printf("Error decoding position for %s:%vs\n", gtid, err.Error()) 206 } 207 stopPosition, err = binlogplayer.DecodePosition(stopPos) 208 if err != nil { 209 fmt.Printf("Error decoding position for %s:%vs\n", stopPos, err.Error()) 210 } 211 if currentPosition.AtLeast(stopPosition) { 212 log.Infof("Finished streaming keyspace %s from %s upto %s, total rows seen %d", keyspace, startPos, stopPos, totalRowsForTable) 213 return "", "", true, true, nil 214 } 215 216 if testResumability { 217 return gtid, stopPos, false, fieldsPrinted, nil 218 } 219 case io.EOF: 220 log.Infof("stream ended before reaching stop pos") 221 fmt.Printf("stream ended before reaching stop pos\n") 222 return "", "", false, fieldsPrinted, nil 223 default: 224 log.Errorf("remote error: %s, returning gtid %s, stopPos %s", err, gtid, stopPos) 225 fmt.Printf("remote error: %s, returning gtid %s, stopPos %s\n", err.Error(), gtid, stopPos) 226 return gtid, stopPos, false, fieldsPrinted, err 227 } 228 } 229 } 230 231 func output(filename, s string) { 232 f, err := os.OpenFile(filename+".log", 233 os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644) 234 if err != nil { 235 log.Errorf(err.Error()) 236 } 237 defer f.Close() 238 if _, err := f.WriteString(s + "\n"); err != nil { 239 log.Errorf(err.Error()) 240 } 241 log.Infof("Writing to %s.log: %s", filename, s) 242 } 243 244 func outputHeader(plan *TablePlan) { 245 s := getHeader(plan) 246 output(plan.keyspace, s) 247 } 248 249 func getHeader(plan *TablePlan) string { 250 s := "" 251 for _, field := range plan.fields { 252 s += field.Name + "\t" 253 } 254 s += "op\ttimestamp\tgtid" 255 return s 256 } 257 258 func outputRows(plan *TablePlan, rows []*RowLog) { 259 for _, row := range rows { 260 s := "" 261 for _, val := range row.values { 262 s += val + "\t" 263 } 264 s += fmt.Sprintf("%s\t%s\t%s", row.op, row.when, row.gtid) 265 output(plan.keyspace, s) 266 } 267 } 268 269 func mustSend(plan *TablePlan, afterVals, beforeVals []string) bool { 270 if len(afterVals) > 0 { 271 if _, ok := plan.allowedIds[afterVals[plan.pkIndex]]; ok { 272 return true 273 } 274 } 275 if len(beforeVals) > 0 { 276 if _, ok := plan.allowedIds[beforeVals[plan.pkIndex]]; ok { 277 return true 278 } 279 } 280 return false 281 } 282 283 type RowLog struct { 284 op string 285 values []string 286 when string 287 gtid string 288 } 289 290 func processRowEvent(plan *TablePlan, gtid string, ev *binlogdatapb.VEvent) []*RowLog { 291 op := "insert" 292 var rowLogs []*RowLog 293 for _, change := range ev.RowEvent.RowChanges { 294 var after, before []sqltypes.Value 295 var afterVals, beforeVals []string 296 if change.After != nil { 297 after = sqltypes.MakeRowTrusted(plan.fields, change.After) 298 } 299 if change.Before != nil { 300 before = sqltypes.MakeRowTrusted(plan.fields, change.Before) 301 } 302 for _, val := range after { 303 bytes, err := val.ToBytes() 304 if err != nil { 305 panic(err) 306 } 307 afterVals = append(afterVals, string(bytes)) 308 } 309 for _, val := range before { 310 bytes, err := val.ToBytes() 311 if err != nil { 312 panic(err) 313 } 314 beforeVals = append(beforeVals, string(bytes)) 315 } 316 if !mustSend(plan, afterVals, beforeVals) { 317 continue 318 } 319 320 if len(after) > 0 && len(before) > 0 { 321 op = "update" 322 } else if len(before) > 0 { 323 op = "delete" 324 afterVals = beforeVals 325 } 326 327 rowLog := &RowLog{ 328 op: op, 329 values: afterVals, 330 when: time.Unix(ev.Timestamp, 0).Format(time.RFC3339), 331 gtid: gtid, 332 } 333 rowLogs = append(rowLogs, rowLog) 334 } 335 return rowLogs 336 } 337 338 func getTablePlan(keyspace string, fields []*querypb.Field, table, pk string, ids []string) *TablePlan { 339 allowedIds := make(map[string]bool) 340 for _, id := range ids { 341 allowedIds[id] = true 342 } 343 var pkIndex int64 344 for i, field := range fields { 345 if field.Name == pk { 346 pkIndex = int64(i) 347 break 348 } 349 } 350 return &TablePlan{ 351 table: table, 352 pk: pk, 353 allowedIds: allowedIds, 354 pkIndex: pkIndex, 355 fields: fields, 356 keyspace: keyspace, 357 } 358 } 359 360 type TablePlan struct { 361 table, pk string 362 allowedIds map[string]bool 363 pkIndex int64 364 fields []*querypb.Field 365 keyspace string 366 } 367 368 func getFlavor(ctx context.Context, server, keyspace string) string { 369 curPos, err := getPosition(ctx, server, keyspace, "0") 370 if err != nil { 371 return "" 372 } 373 if curPos == "" { 374 return "" 375 } 376 flavor := strings.Split(curPos, "/")[0] 377 return flavor 378 } 379 380 func getTablet(ctx context.Context, ts *topo.Server, cells []string, keyspace string) string { 381 picker, err := discovery.NewTabletPicker(ts, cells, keyspace, "0", "primary") 382 if err != nil { 383 return "" 384 } 385 tab, err := picker.PickForStreaming(ctx) 386 if err != nil { 387 return "" 388 } 389 tabletId := fmt.Sprintf("%s-%d", tab.Alias.Cell, tab.Alias.Uid) 390 return tabletId 391 392 } 393 func trickGlog() { 394 var args []string 395 os.Args, args = os.Args[:1], os.Args[1:] 396 defer func() { os.Args = append(os.Args, args...) }() 397 flag.Parse() 398 } 399 400 var testResumability bool 401 402 func parseCommandLine() *RowLogConfig { 403 trickGlog() 404 sourceKeyspace := pflag.StringP("source", "s", "", "") 405 targetKeyspace := pflag.StringP("target", "t", "", "") 406 ids := pflag.StringSlice("ids", nil, "") 407 pk := pflag.String("pk", "", "") 408 table := pflag.String("table", "", "") 409 vtgate := pflag.String("vtgate", "", "") 410 vtctld := pflag.String("vtctld", "", "") 411 cells := pflag.StringSlice("cells", nil, "") 412 413 pflag.BoolVar(&testResumability, "test_resumability", testResumability, "set to test stream resumability") 414 415 pflag.Parse() 416 417 return &RowLogConfig{ 418 sourceKeyspace: *sourceKeyspace, 419 targetKeyspace: *targetKeyspace, 420 table: *table, 421 pk: *pk, 422 ids: *ids, 423 vtctld: *vtctld, 424 vtgate: *vtgate, 425 cells: *cells, 426 } 427 } 428 429 func processPositionResult(gtidset string) (string, string) { 430 gtids := strings.Trim(strings.Replace(gtidset, "|", "", 10), " \n") 431 arr := strings.Split(gtids, ":") 432 subs := strings.Split(arr[1], "-") 433 id, err := strconv.Atoi(subs[0]) 434 if err != nil { 435 fmt.Printf(err.Error()) 436 return "", "" 437 } 438 firstPos := arr[0] + ":" + strconv.Itoa(id) // subs[0] 439 lastPos := gtids 440 return firstPos, lastPos 441 } 442 443 // hack, should read json in a structured manner 444 func parseExecOutput(result string) string { 445 resultMap := make(map[string]any) 446 err := json.Unmarshal([]byte(result), &resultMap) 447 if err != nil { 448 fmt.Printf("error parsing result json %s", result) 449 return "" 450 } 451 rows := reflect.ValueOf(resultMap["rows"]) 452 s := fmt.Sprintf("%v", rows) 453 s = strings.Trim(s, "[]") 454 return s 455 } 456 457 func getPositions(ctx context.Context, server, tablet string) (string, string, error) { 458 query := "select GTID_SUBTRACT(@@GLOBAL.gtid_executed, GTID_SUBTRACT(@@GLOBAL.gtid_executed, @@GLOBAL.gtid_purged));" 459 results, err := execVtctl(ctx, server, []string{"ExecuteFetchAsDba", "--json", tablet, query}) 460 if err != nil { 461 fmt.Println(err) 462 log.Errorf(err.Error()) 463 return "", "", err 464 } 465 firstPos := parseExecOutput(strings.Join(results, "")) 466 467 query = "select @@GLOBAL.gtid_executed;" 468 results, err = execVtctl(ctx, server, []string{"ExecuteFetchAsDba", "--json", tablet, query}) 469 if err != nil { 470 fmt.Println(err) 471 log.Errorf(err.Error()) 472 return "", "", err 473 } 474 lastPos := parseExecOutput(strings.Join(results, "")) 475 return firstPos, lastPos, nil 476 } 477 478 func getPosition(ctx context.Context, server, keyspace, shard string) (string, error) { 479 results, err := execVtctl(ctx, server, []string{"ShardReplicationPositions", fmt.Sprintf("%s:%s", keyspace, shard)}) 480 if err != nil { 481 fmt.Println(err) 482 return "", err 483 } 484 splits := strings.Split(results[0], " ") 485 return splits[8], nil 486 } 487 488 func execVtctl(ctx context.Context, server string, args []string) ([]string, error) { 489 client, err := vtctlclient.New(server) 490 if err != nil { 491 fmt.Println(err) 492 return nil, err 493 } 494 if client == nil { 495 fmt.Printf("Unable to contact %s\n", server) 496 return nil, fmt.Errorf("unable to contact %s", server) 497 } 498 defer client.Close() 499 500 stream, err := client.ExecuteVtctlCommand(ctx, args, 10*time.Second) 501 if err != nil { 502 return nil, fmt.Errorf("cannot execute remote command: %v", err) 503 } 504 505 var results []string 506 for { 507 e, err := stream.Recv() 508 switch err { 509 case nil: 510 if e.Level == logutilpb.Level_CONSOLE { 511 results = append(results, e.Value) 512 } 513 case io.EOF: 514 return results, nil 515 default: 516 log.Errorf("remote error: %v", err) 517 return nil, fmt.Errorf("remote error: %v", err) 518 } 519 } 520 }