diff --git a/go/vt/mysqlctl/backup_blackbox_test.go b/go/vt/mysqlctl/backup_blackbox_test.go index d9f09d7e284..2b749bea822 100644 --- a/go/vt/mysqlctl/backup_blackbox_test.go +++ b/go/vt/mysqlctl/backup_blackbox_test.go @@ -24,6 +24,7 @@ import ( "fmt" "os" "path" + "strconv" "strings" "testing" "time" @@ -613,55 +614,8 @@ func newWriteCloseFailFirstWrite(firstWriteDone bool) *writeCloseFailFirstWrite } } -func TestAA(t *testing.T) { - ctx := utils.LeakCheckContext(t) - - // Set up local backup directory - id := fmt.Sprintf("%d", time.Now().UnixNano()) - backupRoot := fmt.Sprintf("testdata/builtinbackup_test_%s", id) - filebackupstorage.FileBackupStorageRoot = backupRoot - require.NoError(t, createBackupDir(backupRoot, "innodb", "log", "datadir")) - dataDir := path.Join(backupRoot, "datadir") - // Add some files under data directory to force backup to execute semaphore acquire inside - // backupFiles() method (https://github.com/vitessio/vitess/blob/main/go/vt/mysqlctl/builtinbackupengine.go#L483). - require.NoError(t, createBackupDir(dataDir, "test1")) - require.NoError(t, createBackupDir(dataDir, "test2")) - require.NoError(t, createBackupFiles(path.Join(dataDir, "test1"), 2, "ibd")) - require.NoError(t, createBackupFiles(path.Join(dataDir, "test2"), 2, "ibd")) - defer os.RemoveAll(backupRoot) - - needIt, err := needInnoDBRedoLogSubdir() - require.NoError(t, err) - if needIt { - fpath := path.Join("log", mysql.DynamicRedoLogSubdir) - if err := createBackupDir(backupRoot, fpath); err != nil { - require.Failf(t, err.Error(), "failed to create directory: %s", fpath) - } - } - - // Set up topo - keyspace, shard := "mykeyspace", "-" - ts := memorytopo.NewServer(ctx, "cell1") - defer ts.Close() - - require.NoError(t, ts.CreateKeyspace(ctx, keyspace, &topodata.Keyspace{})) - require.NoError(t, ts.CreateShard(ctx, keyspace, shard)) - - tablet := topo.NewTablet(100, "cell1", "mykeyspace-00-80-0100") - tablet.Keyspace = keyspace - tablet.Shard = shard - - require.NoError(t, ts.CreateTablet(ctx, tablet)) - - _, err = ts.UpdateShardFields(ctx, keyspace, shard, func(si *topo.ShardInfo) error { - si.PrimaryAlias = &topodata.TabletAlias{Uid: 100, Cell: "cell1"} - - now := time.Now() - si.PrimaryTermStartTime = &vttime.Time{Seconds: int64(now.Second()), Nanoseconds: int32(now.Nanosecond())} - - return nil - }) - require.NoError(t, err) +func TestExecuteBackupFailToWriteEachFileOnlyOnce(t *testing.T) { + ctx, backupRoot, keyspace, shard, ts := setupCluster(t, 2, 2) bufferPerFiles := make(map[string]*writeCloseFailFirstWrite) be := &mysqlctl.BuiltinBackupEngine{} @@ -717,14 +671,161 @@ func TestAA(t *testing.T) { MysqlShutdownTimeout: mysqlShutdownTimeout, }, bh) - for _, event := range logger.Events { - fmt.Println(event.String()) + expectedLogs := []string{ + "Backing up file: test1/0.ibd (attempt 1/2)", + "Backing up file: test1/1.ibd (attempt 1/2)", + "Backing up file: test2/0.ibd (attempt 1/2)", + "Backing up file: test2/1.ibd (attempt 1/2)", + + "Failed backing up \"test1/0.ibd\" (attempt 1/2)", + "Failed backing up \"test1/1.ibd\" (attempt 1/2)", + "Failed backing up \"test2/0.ibd\" (attempt 1/2)", + "Failed backing up \"test2/1.ibd\" (attempt 1/2)", + + "Backing up file: test1/0.ibd (attempt 2/2)", + "Backing up file: test1/1.ibd (attempt 2/2)", + "Backing up file: test2/0.ibd (attempt 2/2)", + "Backing up file: test2/1.ibd (attempt 2/2)", + + "Completed backing up \"test1/0.ibd\" (attempt 2/2)", + "Completed backing up \"test1/1.ibd\" (attempt 2/2)", + "Completed backing up \"test2/0.ibd\" (attempt 2/2)", + "Completed backing up \"test2/1.ibd\" (attempt 2/2)", + + "Backing up file MANIFEST (attempt 1/2)", + "Failed backing up MANIFEST (attempt 1/2)", + "Backing up file MANIFEST (attempt 2/2)", + "Completed backing up MANIFEST (attempt 2/2)", } + assertLogs(t, expectedLogs, logger) + require.NoError(t, err) require.Equal(t, mysqlctl.BackupUsable, backupResult) } +func TestExecuteBackupFailToWriteFileEachTwice(t *testing.T) { + ctx, backupRoot, keyspace, shard, ts := setupCluster(t, 1, 1) + + bufferPerFiles := make(map[string]*writeCloseFailFirstWrite) + be := &mysqlctl.BuiltinBackupEngine{} + bh := &mysqlctl.FakeBackupHandle{} + bh.AddFileReturnF = func(filename string) mysqlctl.FakeBackupHandleAddFileReturn { + newBuffer := newWriteCloseFailFirstWrite(false) + bufferPerFiles[filename] = newBuffer + + return mysqlctl.FakeBackupHandleAddFileReturn{WriteCloser: newBuffer} + } + + // Spin up a fake daemon to be used in backups. It needs to be allowed to receive: + // "STOP REPLICA", "START REPLICA", in that order. + fakedb := fakesqldb.New(t) + defer fakedb.Close() + mysqld := mysqlctl.NewFakeMysqlDaemon(fakedb) + defer mysqld.Close() + mysqld.ExpectedExecuteSuperQueryList = []string{"STOP REPLICA", "START REPLICA"} + + logger := logutil.NewMemoryLogger() + backupResult, err := be.ExecuteBackup(ctx, mysqlctl.BackupParams{ + Logger: logger, + Mysqld: mysqld, + Cnf: &mysqlctl.Mycnf{ + InnodbDataHomeDir: path.Join(backupRoot, "innodb"), + InnodbLogGroupHomeDir: path.Join(backupRoot, "log"), + DataDir: path.Join(backupRoot, "datadir"), + }, + Stats: backupstats.NewFakeStats(), + Concurrency: 1, + HookExtraEnv: map[string]string{}, + TopoServer: ts, + Keyspace: keyspace, + Shard: shard, + MysqlShutdownTimeout: mysqlShutdownTimeout, + }, bh) + + expectedLogs := []string{ + "Failed backing up \"test1/0.ibd\" (attempt 1/2)", + "Failed backing up \"test1/0.ibd\" (attempt 2/2)", + } + + assertLogs(t, expectedLogs, logger) + + require.ErrorContains(t, err, "failing first write") + require.Equal(t, mysqlctl.BackupUnusable, backupResult) +} + +func assertLogs(t *testing.T, expectedLogs []string, logger *logutil.MemoryLogger) { + for _, log := range expectedLogs { + var found bool + for _, event := range logger.Events { + if log == event.GetValue() { + found = true + break + } + } + if !found { + require.Failf(t, "missing log line", "%s is missing from the logs", log) + } + } +} + +func setupCluster(t *testing.T, dirs, filesPerDir int) (ctx context.Context, backupRoot string, keyspace string, shard string, ts *topo.Server) { + ctx = utils.LeakCheckContext(t) + + // Set up local backup directory + id := fmt.Sprintf("%d", time.Now().UnixNano()) + backupRoot = fmt.Sprintf("testdata/builtinbackup_test_%s", id) + filebackupstorage.FileBackupStorageRoot = backupRoot + require.NoError(t, createBackupDir(backupRoot, "innodb", "log", "datadir")) + dataDir := path.Join(backupRoot, "datadir") + // Add some files under data directory to force backup to execute semaphore acquire inside + // backupFiles() method (https://github.com/vitessio/vitess/blob/main/go/vt/mysqlctl/builtinbackupengine.go#L483). + for dirI := range dirs { + dirName := "test" + strconv.Itoa(dirI+1) + require.NoError(t, createBackupDir(dataDir, dirName)) + require.NoError(t, createBackupFiles(path.Join(dataDir, dirName), filesPerDir, "ibd")) + } + t.Cleanup(func() { + require.NoError(t, os.RemoveAll(backupRoot)) + }) + + needIt, err := needInnoDBRedoLogSubdir() + require.NoError(t, err) + if needIt { + fpath := path.Join("log", mysql.DynamicRedoLogSubdir) + if err := createBackupDir(backupRoot, fpath); err != nil { + require.Failf(t, err.Error(), "failed to create directory: %s", fpath) + } + } + + // Set up topo + keyspace, shard = "mykeyspace", "-" + ts = memorytopo.NewServer(ctx, "cell1") + t.Cleanup(func() { + ts.Close() + }) + + require.NoError(t, ts.CreateKeyspace(ctx, keyspace, &topodata.Keyspace{})) + require.NoError(t, ts.CreateShard(ctx, keyspace, shard)) + + tablet := topo.NewTablet(100, "cell1", "mykeyspace-00-80-0100") + tablet.Keyspace = keyspace + tablet.Shard = shard + + require.NoError(t, ts.CreateTablet(ctx, tablet)) + + _, err = ts.UpdateShardFields(ctx, keyspace, shard, func(si *topo.ShardInfo) error { + si.PrimaryAlias = &topodata.TabletAlias{Uid: 100, Cell: "cell1"} + + now := time.Now() + si.PrimaryTermStartTime = &vttime.Time{Seconds: int64(now.Second()), Nanoseconds: int32(now.Nanosecond())} + + return nil + }) + require.NoError(t, err) + return ctx, backupRoot, keyspace, shard, ts +} + // needInnoDBRedoLogSubdir indicates whether we need to create a redo log subdirectory. // Starting with MySQL 8.0.30, the InnoDB redo logs are stored in a subdirectory of the // (/. by default) called "#innodb_redo". See: