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  }