vreplication: fix vreplication timing metrics

Several of the vreplication metrics were recently updated to no longer be
correct. Specifically time.Now() is no longer executed when the function
starts and is instead executed when the defer statement is called after the end
of the function.

This updates the metrics to properly execute time.Now() at the start
of the functions.

Signed-off-by: Dylan Visher <dvisher@figma.com>

go/vt/vttablet/tabletmanager/vreplication/vcopier.go

@@ -146,9 +146,7 @@ func (vc *vcopier) copyNext(ctx context.Context, settings binlogplayer.VRSetting
 func (vc *vcopier) catchup(ctx context.Context, copyState map[string]*sqltypes.Result) error {
 	ctx, cancel := context.WithCancel(ctx)
 	defer cancel()
-	defer func() {
-		vc.vr.stats.PhaseTimings.Record("catchup", time.Now())
-	}()
+	defer vc.vr.stats.PhaseTimings.Record("catchup", time.Now())
 
 	settings, err := binlogplayer.ReadVRSettings(vc.vr.dbClient, vc.vr.id)
 	if err != nil {
@@ -198,10 +196,8 @@ func (vc *vcopier) catchup(ctx context.Context, copyState map[string]*sqltypes.R
 // committed with the lastpk. This allows for consistent resumability.
 func (vc *vcopier) copyTable(ctx context.Context, tableName string, copyState map[string]*sqltypes.Result) error {
 	defer vc.vr.dbClient.Rollback()
-	defer func() {
-		vc.vr.stats.PhaseTimings.Record("copy", time.Now())
-		vc.vr.stats.CopyLoopCount.Add(1)
-	}()
+	defer vc.vr.stats.PhaseTimings.Record("copy", time.Now())
+	defer vc.vr.stats.CopyLoopCount.Add(1)
 
 	log.Infof("Copying table %s, lastpk: %v", tableName, copyState[tableName])
 
@@ -334,9 +330,7 @@ func (vc *vcopier) copyTable(ctx context.Context, tableName string, copyState ma
 }
 
 func (vc *vcopier) fastForward(ctx context.Context, copyState map[string]*sqltypes.Result, gtid string) error {
-	defer func() {
-		vc.vr.stats.PhaseTimings.Record("fastforward", time.Now())
-	}()
+	defer vc.vr.stats.PhaseTimings.Record("fastforward", time.Now())
 	pos, err := mysql.DecodePosition(gtid)
 	if err != nil {
 		return err