Instrument chaincode container build

Add metric for chaincode container build duration.

FAB-12868 #done

Change-Id: Ie28259ef3d6214616f6ef8d4eb5bbcdb13a4c599
Signed-off-by: Will Lahti <wtlahti@us.ibm.com>
Signed-off-by: Matthew Sykes <sykesmat@us.ibm.com>

Author: wlahti

core/chaincode/chaincode_support_test.go

@@ -186,7 +186,7 @@ func initMockPeer(chainIDs ...string) (*ChaincodeSupport, error) {
 		mockAclProvider,
 		container.NewVMController(
 			map[string]container.VMProvider{
-				dockercontroller.ContainerType: dockercontroller.NewProvider("", ""),
+				dockercontroller.ContainerType: dockercontroller.NewProvider("", "", &disabled.Provider{}),
 				inproccontroller.ContainerType: ipRegistry,
 			},
 		),

core/chaincode/exectransaction_test.go

@@ -134,7 +134,7 @@ func initPeer(chainIDs ...string) (net.Listener, *ChaincodeSupport, func(), erro
 		aclmgmt.NewACLProvider(func(string) channelconfig.Resources { return nil }),
 		container.NewVMController(
 			map[string]container.VMProvider{
-				dockercontroller.ContainerType: dockercontroller.NewProvider("", ""),
+				dockercontroller.ContainerType: dockercontroller.NewProvider("", "", &disabled.Provider{}),
 				inproccontroller.ContainerType: ipRegistry,
 			},
 		),

core/container/dockercontroller/dockercontroller.go

@@ -16,11 +16,13 @@ import (
 	"fmt"
 	"io"
 	"regexp"
+	"strconv"
 	"strings"
 	"time"
 
 	"github.com/fsouza/go-dockerclient"
 	"github.com/hyperledger/fabric/common/flogging"
+	"github.com/hyperledger/fabric/common/metrics"
 	"github.com/hyperledger/fabric/common/util"
 	"github.com/hyperledger/fabric/core/container"
 	"github.com/hyperledger/fabric/core/container/ccintf"
@@ -47,6 +49,7 @@ type DockerVM struct {
 	getClientFnc getClient
 	PeerID       string
 	NetworkID    string
+	BuildMetrics *BuildMetrics
 }
 
 // dockerClient represents a docker client
@@ -80,33 +83,36 @@ type dockerClient interface {
 	PingWithContext(context.Context) error
 }
 
-// Controller implements container.VMProvider
+// Provider implements container.VMProvider
 type Provider struct {
-	PeerID    string
-	NetworkID string
+	PeerID       string
+	NetworkID    string
+	BuildMetrics *BuildMetrics
 }
 
 // NewProvider creates a new instance of Provider
-func NewProvider(peerID, networkID string) *Provider {
+func NewProvider(peerID, networkID string, metricsProvider metrics.Provider) *Provider {
 	return &Provider{
-		PeerID:    peerID,
-		NetworkID: networkID,
+		PeerID:       peerID,
+		NetworkID:    networkID,
+		BuildMetrics: NewBuildMetrics(metricsProvider),
 	}
 }
 
 // NewVM creates a new DockerVM instance
 func (p *Provider) NewVM() container.VM {
-	return NewDockerVM(p.PeerID, p.NetworkID)
+	return NewDockerVM(p.PeerID, p.NetworkID, p.BuildMetrics)
 }
 
 // NewDockerVM returns a new DockerVM instance
-func NewDockerVM(peerID, networkID string) *DockerVM {
-	vm := DockerVM{
-		PeerID:    peerID,
-		NetworkID: networkID,
+func NewDockerVM(peerID, networkID string, buildMetrics *BuildMetrics) *DockerVM {
+	vm := &DockerVM{
+		PeerID:       peerID,
+		NetworkID:    networkID,
+		getClientFnc: getDockerClient,
+		BuildMetrics: buildMetrics,
 	}
-	vm.getClientFnc = getDockerClient
-	return &vm
+	return vm
 }
 
 func getDockerClient() (dockerClient, error) {
@@ -201,7 +207,15 @@ func (vm *DockerVM) deployImage(client dockerClient, ccid ccintf.CCID,
 		OutputStream: outputbuf,
 	}
 
-	if err := client.BuildImage(opts); err != nil {
+	startTime := time.Now()
+	err = client.BuildImage(opts)
+
+	vm.BuildMetrics.ChaincodeContainerBuildDuration.With(
+		"chaincode", ccid.Name+":"+ccid.Version,
+		"success", strconv.FormatBool(err == nil),
+	).Observe(time.Since(startTime).Seconds())
+
+	if err != nil {
 		dockerLogger.Errorf("Error building images: %s", err)
 		dockerLogger.Errorf("Image Output:\n********************\n%s\n********************", outputbuf.String())
 		return err

core/container/dockercontroller/dockercontroller_test.go

@@ -19,12 +19,15 @@ import (
 	"time"
 
 	docker "github.com/fsouza/go-dockerclient"
+	"github.com/hyperledger/fabric/common/metrics/disabled"
+	"github.com/hyperledger/fabric/common/metrics/metricsfakes"
 	"github.com/hyperledger/fabric/common/util"
 	"github.com/hyperledger/fabric/core/chaincode/platforms"
 	"github.com/hyperledger/fabric/core/chaincode/platforms/golang"
 	"github.com/hyperledger/fabric/core/container/ccintf"
 	coreutil "github.com/hyperledger/fabric/core/testutil"
 	pb "github.com/hyperledger/fabric/protos/peer"
+	. "github.com/onsi/gomega"
 	"github.com/spf13/viper"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
@@ -33,7 +36,7 @@ import (
 // This test used to be part of an integration style test in core/container, moved to here
 func TestIntegrationPath(t *testing.T) {
 	coreutil.SetupTestConfig()
-	dc := NewDockerVM("", util.GenerateUUID())
+	dc := NewDockerVM("", util.GenerateUUID(), NewBuildMetrics(&disabled.Provider{}))
 	ccid := ccintf.CCID{Name: "simple"}
 
 	err := dc.Start(ccid, nil, nil, nil, InMemBuilder{})
@@ -77,8 +80,18 @@ func TestGetDockerHostConfig(t *testing.T) {
 }
 
 func Test_Start(t *testing.T) {
-	dvm := DockerVM{}
-	ccid := ccintf.CCID{Name: "simple"}
+	gt := NewGomegaWithT(t)
+	fakeChaincodeContainerBuildDuration := &metricsfakes.Histogram{}
+	fakeChaincodeContainerBuildDuration.WithReturns(fakeChaincodeContainerBuildDuration)
+	dvm := DockerVM{
+		BuildMetrics: &BuildMetrics{
+			ChaincodeContainerBuildDuration: fakeChaincodeContainerBuildDuration,
+		},
+	}
+	ccid := ccintf.CCID{
+		Name:    "simple",
+		Version: "1.0",
+	}
 	args := make([]string, 1)
 	env := make([]string, 1)
 	files := map[string][]byte{
@@ -90,25 +103,25 @@ func Test_Start(t *testing.T) {
 	dvm.getClientFnc = getMockClient
 	getClientErr = true
 	err := dvm.Start(ccid, args, env, files, nil)
-	testerr(t, err, false)
+	gt.Expect(err).To(HaveOccurred())
 	getClientErr = false
 
 	// case 2: dockerClient.CreateContainer returns error
 	createErr = true
 	err = dvm.Start(ccid, args, env, files, nil)
-	testerr(t, err, false)
+	gt.Expect(err).To(HaveOccurred())
 	createErr = false
 
 	// case 3: dockerClient.UploadToContainer returns error
 	uploadErr = true
 	err = dvm.Start(ccid, args, env, files, nil)
-	testerr(t, err, false)
+	gt.Expect(err).To(HaveOccurred())
 	uploadErr = false
 
 	// case 4: dockerClient.StartContainer returns docker.noSuchImgErr
 	noSuchImgErr = true
 	err = dvm.Start(ccid, args, env, files, nil)
-	testerr(t, err, false)
+	gt.Expect(err).To(HaveOccurred())
 
 	chaincodePath := "github.com/hyperledger/fabric/examples/chaincode/go/example01/cmd"
 	spec := &pb.ChaincodeSpec{
@@ -138,34 +151,43 @@ func Test_Start(t *testing.T) {
 	viper.Set("vm.docker.attachStdout", true)
 	startErr = true
 	err = dvm.Start(ccid, args, env, files, bldr)
-	testerr(t, err, false)
+	gt.Expect(err).To(HaveOccurred())
+
+	gt.Expect(fakeChaincodeContainerBuildDuration.WithCallCount()).To(Equal(1))
+	labelValues := fakeChaincodeContainerBuildDuration.WithArgsForCall(0)
+	gt.Expect(labelValues).To(Equal([]string{
+		"chaincode", "simple:1.0",
+		"success", "true",
+	}))
+	gt.Expect(fakeChaincodeContainerBuildDuration.ObserveArgsForCall(0)).NotTo(BeZero())
+	gt.Expect(fakeChaincodeContainerBuildDuration.ObserveArgsForCall(0)).To(BeNumerically("<", 1.0))
 	startErr = false
 
 	// Success cases
 	err = dvm.Start(ccid, args, env, files, bldr)
-	testerr(t, err, true)
+	gt.Expect(err).NotTo(HaveOccurred())
 	noSuchImgErr = false
 
 	// dockerClient.StopContainer returns error
 	stopErr = true
 	err = dvm.Start(ccid, args, env, files, nil)
-	testerr(t, err, true)
+	gt.Expect(err).NotTo(HaveOccurred())
 	stopErr = false
 
 	// dockerClient.KillContainer returns error
 	killErr = true
 	err = dvm.Start(ccid, args, env, files, nil)
-	testerr(t, err, true)
+	gt.Expect(err).NotTo(HaveOccurred())
 	killErr = false
 
 	// dockerClient.RemoveContainer returns error
 	removeErr = true
 	err = dvm.Start(ccid, args, env, files, nil)
-	testerr(t, err, true)
+	gt.Expect(err).NotTo(HaveOccurred())
 	removeErr = false
 
 	err = dvm.Start(ccid, args, env, files, nil)
-	testerr(t, err, true)
+	gt.Expect(err).NotTo(HaveOccurred())
 }
 
 func Test_Stop(t *testing.T) {
@@ -176,12 +198,12 @@ func Test_Stop(t *testing.T) {
 	getClientErr = true
 	dvm.getClientFnc = getMockClient
 	err := dvm.Stop(ccid, 10, true, true)
-	testerr(t, err, false)
+	assert.Error(t, err)
 	getClientErr = false
 
 	// Success case
 	err = dvm.Stop(ccid, 10, true, true)
-	testerr(t, err, true)
+	assert.NoError(t, err)
 }
 
 func Test_HealthCheck(t *testing.T) {
@@ -308,14 +330,6 @@ func (imb InMemBuilder) Build() (io.Reader, error) {
 	return inputbuf, nil
 }
 
-func testerr(t *testing.T, err error, succ bool) {
-	if succ {
-		assert.NoError(t, err, "Expected success but got error")
-	} else {
-		assert.Error(t, err, "Expected failure but succeeded")
-	}
-}
-
 func getMockClient() (dockerClient, error) {
 	if getClientErr {
 		return nil, errors.New("Failed to get client")

core/container/dockercontroller/metrics.go

@@ -0,0 +1,29 @@
+/*
+Copyright IBM Corp. All Rights Reserved.
+
+SPDX-License-Identifier: Apache-2.0
+*/
+
+package dockercontroller
+
+import "github.com/hyperledger/fabric/common/metrics"
+
+var (
+	chaincodeContainerBuildDuration = metrics.HistogramOpts{
+		Namespace:    "dockercontroller",
+		Name:         "chaincode_container_build_duration",
+		Help:         "The time to build a chaincode container in seconds.",
+		LabelNames:   []string{"chaincode", "success"},
+		StatsdFormat: "%{#fqname}.%{chaincode}.%{success}",
+	}
+)
+
+type BuildMetrics struct {
+	ChaincodeContainerBuildDuration metrics.Histogram
+}
+
+func NewBuildMetrics(p metrics.Provider) *BuildMetrics {
+	return &BuildMetrics{
+		ChaincodeContainerBuildDuration: p.NewHistogram(chaincodeContainerBuildDuration),
+	}
+}

peer/node/start.go

@@ -624,13 +624,16 @@ func registerChaincodeSupport(grpcServer *comm.GRPCServer, ccEndpoint string, ca
 		packageProvider,
 		lsccInst,
 		aclProvider,
-		container.NewVMController(map[string]container.VMProvider{
-			dockercontroller.ContainerType: dockercontroller.NewProvider(
-				viper.GetString("peer.id"),
-				viper.GetString("peer.networkId"),
-			),
-			inproccontroller.ContainerType: ipRegistry,
-		}),
+		container.NewVMController(
+			map[string]container.VMProvider{
+				dockercontroller.ContainerType: dockercontroller.NewProvider(
+					viper.GetString("peer.id"),
+					viper.GetString("peer.networkId"),
+					metricsProvider,
+				),
+				inproccontroller.ContainerType: ipRegistry,
+			},
+		),
 		sccp,
 		pr,
 		peer.DefaultSupport,