pump/storge: Measure time taken to write to disk, to rotate and fsync (pingcap#773)

Author: suzaku

pump/storage/log.go

@@ -22,6 +22,7 @@ import (
 	"os"
 	"sync"
 	"sync/atomic"
+	"time"
 
 	"github.com/pingcap/errors"
 	"github.com/pingcap/log"
@@ -211,7 +212,9 @@ func (lf *logFile) Write(data []byte, sync bool) error {
 		return errors.Annotatef(err, "unable to write to log file: %s", lf.path)
 	}
 	if sync {
+		fsyncT0 := time.Now()
 		err = lf.fdatasync()
+		writeBinlogTimeHistogram.WithLabelValues("fsync").Observe(time.Since(fsyncT0).Seconds())
 		if err != nil {
 			return errors.Annotatef(err, "fdatasync file %s failed", lf.path)
 		}

pump/storage/vlog.go

@@ -25,6 +25,7 @@ import (
 	"strings"
 	"sync"
 	"sync/atomic"
+	"time"
 
 	"github.com/pingcap/errors"
 	"github.com/pingcap/log"
@@ -343,8 +344,24 @@ func (vlog *valueLog) write(reqs []*request) error {
 	var bufReqs []*request
 	vlog.buf.Reset()
 
+	rotate := func() error {
+		err := curFile.finalize()
+		if err != nil {
+			return errors.Annotatef(err, "finalize file %s failed", curFile.path)
+		}
+
+		id := atomic.AddUint32(&vlog.maxFid, 1)
+		curFile, err = vlog.createLogFile(id)
+		if err != nil {
+			return errors.Annotatef(err, "create file id %d failed", id)
+		}
+		return nil
+	}
+
 	toDisk := func() error {
+		writeT0 := time.Now()
 		err := curFile.Write(vlog.buf.Bytes(), vlog.sync)
+		writeBinlogTimeHistogram.WithLabelValues("to_disk").Observe(time.Since(writeT0).Seconds())
 		if err != nil {
 			return errors.Trace(err)
 		}
@@ -357,15 +374,11 @@ func (vlog *valueLog) write(reqs []*request) error {
 
 		// rotate file
 		if curFile.GetWriteOffset() > vlog.opt.ValueLogFileSize {
-			err := curFile.finalize()
-			if err != nil {
-				return errors.Annotatef(err, "finalize file %s failed", curFile.path)
-			}
-
-			id := atomic.AddUint32(&vlog.maxFid, 1)
-			curFile, err = vlog.createLogFile(id)
+			rotateT0 := time.Now()
+			err := rotate()
+			writeBinlogTimeHistogram.WithLabelValues("rotate").Observe(time.Since(rotateT0).Seconds())
 			if err != nil {
-				return errors.Annotatef(err, "create file id %d failed", id)
+				return err
 			}
 		}
 		return nil