Merge branch 'master' of https://github.com/gluster/glusterd2 into cl…

…uster-wide-options

doc/profiling.md

@@ -0,0 +1,89 @@
+Tracking resource usage in Glusterd2
+====================================
+
+Tracing and profiling with `pprof` is intended for developers only. This can be
+used for debugging memory leaks/consumption, slow flows through the code and so
+on. Users will normally not want profiling enabled on their production systems.
+To investigate memory allocations in Glusterd2, it is needed to enable the
+profiling feature. This can be done by adding `"profiling": true` in
+the `--config` file.
+Enabling profiling makes standard Golang pprof endpoints available. For memory
+allocations `/debug/pprof/heap` is most useful.
+Capturing a snapshot of the current allocations in the Glusterd2 is pretty
+simple. On the node running Glusterd2, the go pprof tool command can be used:
+```
+[root@fedora3 glusterd2]# go tool pprof http://localhost:24007/debug/pprof/heap
+File: glusterd2
+Build ID: 7a94c2e498445577aaf7f910d6ef1c3adc19d553
+Type: inuse_space
+Time: Nov 28, 2018 at 2:55pm (IST)
+Entering interactive mode (type "help" for commands, "o" for options)
+(pprof)
+```
+
+For working with the size of the allocations, it is helpful to set all sizes to
+`megabytes`, otherwise `auto` is used as a `unit` and that would add human
+readable B, kB, MB postfixes. This however is not useful for sorting with
+scripts. So, set the `unit` to `megabytes` instead:
+
+```
+(pprof) unit=megabytes
+```
+
+```
+(pprof) top
+Showing nodes accounting for 330.75MB, 98.52% of 335.73MB total
+Dropped 305 nodes (cum <= 1.68MB)
+Showing top 10 nodes out of 14
+      flat  flat%   sum%        cum   cum%
+     326MB 97.10% 97.10%      326MB 97.10%  github.com/gluster/glusterd2/pkg/sunrpc.ReadFullRecord /root/work/src/github.com/gluster/glusterd2/pkg/sunrpc/record.go
+    2.38MB  0.71% 97.81%     2.38MB  0.71%  github.com/gluster/glusterd2/vendor/github.com/coreos/etcd/rafthttp.startStreamWriter /root/work/src/github.com/gluster/glusterd2/vendor/github.com/coreos/etcd/rafthttp/stream.go
+    2.38MB  0.71% 98.52%     4.77MB  1.42%  github.com/gluster/glusterd2/vendor/github.com/coreos/etcd/rafthttp.startPeer /root/work/src/github.com/gluster/glusterd2/vendor/github.com/coreos/etcd/rafthttp/peer.go
+         0     0% 98.52%   326.01MB 97.10%  github.com/gluster/glusterd2/pkg/sunrpc.(*serverCodec).ReadRequestHeader /root/work/src/github.com/gluster/glusterd2/pkg/sunrpc/servercodec.go
+         0     0% 98.52%     4.83MB  1.44%  github.com/gluster/glusterd2/vendor/github.com/coreos/etcd/etcdserver.(*EtcdServer).apply /root/work/src/github.com/gluster/glusterd2/vendor/github.com/coreos/etcd/etcdserver/server.go
+         0     0% 98.52%     4.83MB  1.44%  github.com/gluster/glusterd2/vendor/github.com/coreos/etcd/etcdserver.(*EtcdServer).applyAll /root/work/src/github.com/gluster/glusterd2/vendor/github.com/coreos/etcd/etcdserver/server.go
+         0     0% 98.52%     4.77MB  1.42%  github.com/gluster/glusterd2/vendor/github.com/coreos/etcd/etcdserver.(*EtcdServer).applyConfChange /root/work/src/github.com/gluster/glusterd2/vendor/github.com/coreos/etcd/etcdserver/server.go
+         0     0% 98.52%     4.83MB  1.44%  github.com/gluster/glusterd2/vendor/github.com/coreos/etcd/etcdserver.(*EtcdServer).applyEntries /root/work/src/github.com/gluster/glusterd2/vendor/github.com/coreos/etcd/etcdserver/server.go
+         0     0% 98.52%     4.83MB  1.44%  github.com/gluster/glusterd2/vendor/github.com/coreos/etcd/etcdserver.(*EtcdServer).run.func6 /root/work/src/github.com/gluster/glusterd2/vendor/github.com/coreos/etcd/etcdserver/server.go
+         0     0% 98.52%     4.83MB  1.44%  github.com/gluster/glusterd2/vendor/github.com/coreos/etcd/pkg/schedule.(*fifo).run /root/work/src/github.com/gluster/glusterd2/vendor/github.com/coreos/etcd/pkg/schedule/schedule.go
+(pprof)
+```
+
+Looking at the above output, we can see that the first line consumes hundreds
+of MB while the other lines are just a fraction of it.
+This makes sure that ReadFullRecord is consuming more memory than required.
+To understand things even more clearly, we can see which line of ReadFullRecord
+consumes the memory. To view that use the list command:
+
+```
+(pprof) list ReadFullRecord
+Total: 335.73MB
+ROUTINE ======================== github.com/gluster/glusterd2/pkg/sunrpc.ReadFullRecord in /root/work/src/github.com/gluster/glusterd2/pkg/sunrpc/clientcodec.go
+    8.11kB     8.11kB (flat, cum) 0.0024% of Total
+         .          .      1:package sunrpc
+         .          .      2:
+         .          .      3:import (
+    8.11kB     8.11kB      4:	"bytes"
+         .          .      5:	"io"
+         .          .      6:	"net"
+         .          .      7:	"net/rpc"
+         .          .      8:	"sync"
+         .          .      9:
+ROUTINE ======================== github.com/gluster/glusterd2/pkg/sunrpc.ReadFullRecord in /root/work/src/github.com/gluster/glusterd2/pkg/sunrpc/record.go
+     326MB      326MB (flat, cum) 97.10% of Total
+         .          .     96:func ReadFullRecord(conn io.Reader) ([]byte, error) {
+         .          .     97:
+         .          .     98:	// In almost all cases, RPC message contain only one fragment which
+         .          .     99:	// is not too big in size. But set a cap on buffer size to prevent
+         .          .    100:	// rogue clients from filling up memory.
+     326MB      326MB    101:	record := bytes.NewBuffer(make([]byte, 0, maxRecordSize))
+         .          .    102:	var fragmentHeader uint32
+         .          .    103:	for {
+         .          .    104:		// Read record fragment header
+         .          .    105:		err := binary.Read(conn, binary.BigEndian, &fragmentHeader)
+         .          .    106:		if err != nil {
+(pprof)
+```
+
+The records allocation is the culprit and we need to look further into
+the code as to why the records is allocating so much and fix it.

e2e/smartvol_ops_test.go

@@ -498,6 +498,7 @@ func editDevice(t *testing.T) {
 	var peerID string
 	for _, peer := range peerList {
 		deviceList, err = client.DeviceList(peer.ID.String(), "")
+		r.Nil(err)
 		if len(deviceList) > 0 {
 			peerID = peer.ID.String()
 			break

glustercli/cmd/glustershd.go

@@ -166,6 +166,6 @@ var selfHealSplitBrainCmd = &cobra.Command{
 		if err != nil {
 			failure(fmt.Sprintf("Failed to resolve split-brain for volume %s\n", volname), err, 1)
 		}
-		fmt.Printf("Split Brain Resolution successfull on volume %s \n", volname)
+		fmt.Printf("Split Brain Resolution successful on volume %s \n", volname)
 	},
 }

glusterd2/brickmux/demultiplex.go

@@ -56,7 +56,7 @@ func Demultiplex(b brick.Brickinfo) error {
 	if rsp.OpRet != 0 {
 		return fmt.Errorf("detach brick RPC request failed; OpRet = %d", rsp.OpRet)
 	}
-	log.WithField("brick", b.String()).Debug("detach request succeded with result")
+	log.WithField("brick", b.String()).Debug("detach request succeeded with result")
 
 	// TODO: Find an alternative to substitute the sleep.
 	// There might be some changes on glusterfsd side related to socket

glusterd2/brickmux/reconcile.go

@@ -66,7 +66,7 @@ func Reconcile() error {
 			// do nothing, fallback to starting a separate process
 			log.WithField("brick", b.String()).Warn(err)
 		default:
-			// log and move on, do not exit; this behaviour can be changed later if necessarry
+			// log and move on, do not exit; this behaviour can be changed later if necessary
 			log.WithField("brick", b.String()).WithError(err).Error("brickmux.Multiplex failed")
 			continue
 		}

glusterd2/commands/snapshot/snapshot-clone.go

@@ -39,16 +39,17 @@ func undoSnapshotClone(c transaction.TxnCtx) error {
 	return nil
 }
 func undoStoreSnapshotClone(c transaction.TxnCtx) error {
-	var vol volume.Volinfo
-	if err := c.Get("volinfo", &vol); err != nil {
-		return err
-	}
+	var (
+		vol volume.Volinfo
+		err error
+	)
 
-	if err := volume.DeleteVolume(vol.Name); err != nil {
+	if err = c.Get("volinfo", &vol); err != nil {
 		return err
 	}
 
-	return nil
+	err = volume.DeleteVolume(vol.Name)
+	return err
 }
 
 func storeSnapshotClone(c transaction.TxnCtx) error {

glusterd2/commands/snapshot/snapshot-delete.go

@@ -83,16 +83,16 @@ func snapshotDelete(c transaction.TxnCtx) error {
 
 func snapshotDeleteStore(c transaction.TxnCtx) error {
 
-	var snapinfo snapshot.Snapinfo
-	if err := c.Get("snapinfo", &snapinfo); err != nil {
-		return err
-	}
-
-	if err := snapshot.DeleteSnapshot(&snapinfo); err != nil {
+	var (
+		snapinfo snapshot.Snapinfo
+		err      error
+	)
+	if err = c.Get("snapinfo", &snapinfo); err != nil {
 		return err
 	}
 
-	return nil
+	err = snapshot.DeleteSnapshot(&snapinfo)
+	return err
 }
 
 /*

glusterd2/commands/volumes/volume-delete.go

@@ -18,16 +18,16 @@ import (
 
 func deleteVolume(c transaction.TxnCtx) error {
 
-	var volinfo volume.Volinfo
-	if err := c.Get("volinfo", &volinfo); err != nil {
-		return err
-	}
-
-	if err := volume.DeleteVolume(volinfo.Name); err != nil {
+	var (
+		volinfo volume.Volinfo
+		err     error
+	)
+	if err = c.Get("volinfo", &volinfo); err != nil {
 		return err
 	}
 
-	return nil
+	err = volume.DeleteVolume(volinfo.Name)
+	return err
 }
 
 func registerVolDeleteStepFuncs() {

glusterd2/commands/volumes/volume-profile.go

@@ -290,6 +290,11 @@ func txnVolumeProfile(c transaction.TxnCtx) error {
 			Op:   int(brick.OpBrickXlatorInfo),
 		}
 		req.Input, err = dict.Serialize(reqDict)
+		if err != nil {
+			c.Logger().WithError(err).WithField(
+				"reqDict", reqDict).Error("failed to convert map to slice of bytes")
+			return err
+		}
 		var rsp brick.GfBrickOpRsp
 		err = client.Call("Brick.OpBrickXlatorInfo", req, &rsp)
 		if err != nil || rsp.OpRet != 0 {

glusterd2/commands/volumes/volume-smartvol-txn.go

@@ -73,7 +73,7 @@ func PrepareBrick(b api.BrickReq, c transaction.TxnCtx) error {
 	}
 
 	// Make Filesystem
-	mkfsOpts := []string{}
+	var mkfsOpts []string
 	if b.Type == "arbiter" {
 		mkfsOpts = []string{"-i", "size=512", "-n", "size=8192", "-i", "maxpct=0"}
 	} else {

glusterd2/config.go

@@ -24,6 +24,7 @@ const (
 	defaultpeeraddress   = ":24008"
 	defaultclientaddress = ":24007"
 	defaultloglevel      = "debug"
+	defaultprofiling     = false
 )
 
 var (
@@ -47,6 +48,7 @@ func initFlags() {
 	flag.String(logging.DirFlag, defaultlogdir, logging.DirHelp)
 	flag.String(logging.FileFlag, defaultlogfile, logging.FileHelp)
 	flag.String(logging.LevelFlag, defaultloglevel, logging.LevelHelp)
+	flag.Bool("profiling", defaultprofiling, "Enable go profiling to collect profile data.")
 
 	// TODO: Change default to false (disabled) in future.
 	flag.Bool("statedump", true, "Enable /statedump endpoint for metrics.")

glusterd2/servers/rest/rest.go

@@ -11,6 +11,7 @@ import (
 
 	"github.com/gluster/glusterd2/glusterd2/middleware"
 	restutils "github.com/gluster/glusterd2/glusterd2/servers/rest/utils"
+	gdutils "github.com/gluster/glusterd2/glusterd2/utils"
 	"github.com/gluster/glusterd2/pkg/api"
 	"github.com/gluster/glusterd2/pkg/tlsmatcher"
 
@@ -85,6 +86,12 @@ func NewMuxed(m cmux.CMux) *GDRest {
 
 	rest.registerRoutes()
 
+	//Enable go profiling
+	profiling := config.GetBool("profiling")
+	if profiling {
+		gdutils.EnableProfiling(rest.Routes)
+	}
+
 	// Set Handler to opencensus HTTP handler to enable tracing
 	// Set chain of ordered middlewares
 	rest.server.Handler = &ochttp.Handler{

glusterd2/transactionv2/engine.go

@@ -134,7 +134,7 @@ func (txnEng *Engine) executePendingTxn(ctx context.Context, txn *Txn) error {
 	for i, step := range txn.Steps {
 		logger.WithField("stepname", step.DoFunc).Debug("running step func on node")
 
-		// a synchronized step is executed only after all pervious steps
+		// a synchronized step is executed only after all previous steps
 		// have been completed successfully by all involved peers.
 		if step.Sync {
 			logger.WithField("stepname", step.DoFunc).Debug("synchronizing txn step")

glusterd2/transactionv2/steprunner.go

@@ -47,7 +47,7 @@ func (sm *stepManager) runStep(ctx context.Context, stepName string, txnCtx tran
 	return transaction.RunStepFuncLocally(ctx, stepName, txnCtx)
 }
 
-// isPrevStepsExecutedOnNode reports that all pervious steps
+// isPrevStepsExecutedOnNode reports that all previous steps
 // have been completed successfully on a given node
 func (sm *stepManager) isPrevStepsExecutedOnNode(ctx context.Context, syncStepIndex int, nodeID uuid.UUID, txnID uuid.UUID, success chan<- struct{}) {
 	txnManager := NewTxnManager(store.Store.Watcher)

glusterd2/utils/pprof.go

@@ -0,0 +1,38 @@
+package utils
+
+//Based on ideas from https://github.com/heketi
+
+import (
+	"net/http"
+	"net/http/pprof"
+	runtime_pprof "runtime/pprof"
+
+	"github.com/gorilla/mux"
+	log "github.com/sirupsen/logrus"
+)
+
+var (
+	basePath = "/debug/pprof/"
+)
+
+func addPath(router *mux.Router, name string, handler http.Handler) {
+	router.Path(basePath + name).Name(name).Handler(handler)
+	log.WithFields(log.Fields{
+		"name":    name,
+		"handler": handler,
+	}).Debug("Starting golang profiling")
+}
+
+//EnableProfiling starts the golang profiling in GD2
+func EnableProfiling(router *mux.Router) {
+	for _, profile := range runtime_pprof.Profiles() {
+		name := profile.Name()
+		handler := pprof.Handler(name)
+		addPath(router, name, handler)
+	}
+
+	addPath(router, "cmdline", http.HandlerFunc(pprof.Cmdline))
+	addPath(router, "profile", http.HandlerFunc(pprof.Profile))
+	addPath(router, "symbol", http.HandlerFunc(pprof.Symbol))
+	addPath(router, "trace", http.HandlerFunc(pprof.Trace))
+}

glusterd2/volgen/common.go

@@ -99,6 +99,9 @@ func DeleteFile(volfileID string) error {
 func ClusterVolfileToFile(v *volume.Volinfo, volfileID string, tmplName string) error {
 	// Use temporary Volume info instead of Volume info from store
 	clusterinfo, err := volume.GetVolumes(context.TODO())
+	if err != nil {
+		return err
+	}
 	for idx, vinfo := range clusterinfo {
 		if v != nil && vinfo.Name == v.Name {
 			clusterinfo[idx] = v

glusterd2/xlator/load.go

@@ -123,19 +123,22 @@ func loadXlator(xlPath string) (*Xlator, error) {
 	// Parent directory name where xlator .so file exists
 	xl.Category = filepath.Base(filepath.Dir(xlPath))
 
-	soOptions := (*[maxOptions]C.volume_option_t)(p)
-	for _, option := range soOptions {
+	// If no options exists in xlator_api table
+	if p != nil {
+		soOptions := (*[maxOptions]C.volume_option_t)(p)
+		for _, option := range soOptions {
 
-		// identify sentinel NULL key which marks the end of options
-		if option.key[0] == nil {
-			break
-		}
+			// identify sentinel NULL key which marks the end of options
+			if option.key[0] == nil {
+				break
+			}
 
-		// &option i.e *C.volume_option_t still points to an address
-		// in memory where that symbol resides as mmap()ed by the call
-		// to dlsym(). We need to copy the contents of that C structure
-		// to its equivalent Go struct before dlclose() happens.
-		xl.Options = append(xl.Options, structifyOption(&option))
+			// &option i.e *C.volume_option_t still points to an address
+			// in memory where that symbol resides as mmap()ed by the call
+			// to dlsym(). We need to copy the contents of that C structure
+			// to its equivalent Go struct before dlclose() happens.
+			xl.Options = append(xl.Options, structifyOption(&option))
+		}
 	}
 
 	if vfunc, ok := validationFuncs[xl.ID]; ok {

pkg/utils/utils.go

@@ -32,6 +32,7 @@ const (
 )
 
 var (
+	// ReservedKeywords are Glusterd2 reserved keywords
 	ReservedKeywords = []string{"all", "volume", "status", "list"}
 )