[FAB-4145] intermittent e2e failure in fabric verify

Added logging in chaincode to help determine which level of the chaincode is executing. Also added environment var in peer0.org1 to redirect the output from the chaincode to the peer's logs Change-Id: Iadf5d692d1a14ac9b5e7529802c92421933f9798 Signed-off-by: Jim Zhang <[email protected]>
hyperledger · May 25, 2017 · 959d99f · 959d99f
1 parent 105d16c
commit 959d99f
Show file tree

Hide file tree

Showing 3 changed files with 38 additions and 37 deletions.
diff --git a/test/fixtures/docker-compose.yaml b/test/fixtures/docker-compose.yaml
@@ -66,6 +66,8 @@ services:
       - CORE_VM_ENDPOINT=unix:///host/var/run/docker.sock
       - CORE_PEER_ID=peer0.org1.example.com
       - CORE_LOGGING_PEER=debug
+      ## the following setting redirects chaincode container logs to the peer container logs
+      - CORE_VM_DOCKER_ATTACHSTDOUT=true
       - CORE_PEER_LOCALMSPID=Org1MSP
       - CORE_PEER_MSPCONFIGPATH=/etc/hyperledger/msp/peer/
       - CORE_PEER_ADDRESS=peer0.org1.example.com:7051

diff --git a/test/fixtures/src/github.com/example_cc/example_cc.go b/test/fixtures/src/github.com/example_cc/example_cc.go
@@ -25,12 +25,15 @@ import (
 	pb "github.com/hyperledger/fabric/protos/peer"
 )
 
+var logger = shim.NewLogger("example_cc0")
+
 // SimpleChaincode example simple Chaincode implementation
 type SimpleChaincode struct {
 }
 
 func (t *SimpleChaincode) Init(stub shim.ChaincodeStubInterface) pb.Response  {
-        fmt.Println("########### example_cc Init ###########")
+	logger.Info("########### example_cc0 Init ###########")
+
 	_, args := stub.GetFunctionAndParameters()
 	var A, B string    // Entities
 	var Aval, Bval int // Asset holdings
@@ -51,7 +54,7 @@ func (t *SimpleChaincode) Init(stub shim.ChaincodeStubInterface) pb.Response  {
 	if err != nil {
 		return shim.Error("Expecting integer value for asset holding")
 	}
-	fmt.Printf("Aval = %d, Bval = %d\n", Aval, Bval)
+	logger.Info("Aval = %d, Bval = %d\n", Aval, Bval)
 
 	// Write the state to the ledger
 	err = stub.PutState(A, []byte(strconv.Itoa(Aval)))
@@ -69,17 +72,14 @@ func (t *SimpleChaincode) Init(stub shim.ChaincodeStubInterface) pb.Response  {
 
 }
 
-func (t *SimpleChaincode) Query(stub shim.ChaincodeStubInterface) pb.Response {
-		return shim.Error("Unknown supported call")
-}
-
 // Transaction makes payment of X units from A to B
 func (t *SimpleChaincode) Invoke(stub shim.ChaincodeStubInterface) pb.Response {
-        fmt.Println("########### example_cc Invoke ###########")
+	logger.Info("########### example_cc0 Invoke ###########")
+
 	function, args := stub.GetFunctionAndParameters()
 
 	if function != "invoke" {
-                return shim.Error("Unknown function call")
+		return shim.Error("Unknown function call")
 	}
 
 	if len(args) < 2 {
@@ -99,7 +99,9 @@ func (t *SimpleChaincode) Invoke(stub shim.ChaincodeStubInterface) pb.Response {
 		// Deletes an entity from its state
 		return t.move(stub, args)
 	}
-	return shim.Error("Unknown action, check the first argument, must be one of 'delete', 'query', or 'move'")
+
+	logger.Errorf("Unknown action, check the first argument, must be one of 'delete', 'query', or 'move'. But got: %v", args[0])
+	return shim.Error(fmt.Sprintf("Unknown action, check the first argument, must be one of 'delete', 'query', or 'move'. But got: %v", args[0]))
 }
 
 func (t *SimpleChaincode) move(stub shim.ChaincodeStubInterface, args []string) pb.Response {
@@ -143,7 +145,7 @@ func (t *SimpleChaincode) move(stub shim.ChaincodeStubInterface, args []string)
 	}
 	Aval = Aval - X
 	Bval = Bval + X
-	fmt.Printf("Aval = %d, Bval = %d\n", Aval, Bval)
+	logger.Infof("Aval = %d, Bval = %d\n", Aval, Bval)
 
 	// Write the state back to the ledger
 	err = stub.PutState(A, []byte(strconv.Itoa(Aval)))
@@ -201,13 +203,13 @@ func (t *SimpleChaincode) query(stub shim.ChaincodeStubInterface, args []string)
 	}
 
 	jsonResp := "{\"Name\":\"" + A + "\",\"Amount\":\"" + string(Avalbytes) + "\"}"
-	fmt.Printf("Query Response:%s\n", jsonResp)
+	logger.Infof("Query Response:%s\n", jsonResp)
 	return shim.Success(Avalbytes)
 }
 
 func main() {
 	err := shim.Start(new(SimpleChaincode))
 	if err != nil {
-		fmt.Printf("Error starting Simple chaincode: %s", err)
+		logger.Errorf("Error starting Simple chaincode: %s", err)
 	}
 }
diff --git a/test/fixtures/src/github.com/example_cc1/example_cc1.go b/test/fixtures/src/github.com/example_cc1/example_cc1.go
@@ -25,39 +25,28 @@ import (
 	pb "github.com/hyperledger/fabric/protos/peer"
 )
 
+var logger = shim.NewLogger("example_cc1")
+
 // SimpleChaincode example simple Chaincode implementation
 type SimpleChaincode struct {
 }
 
 func (t *SimpleChaincode) Init(stub shim.ChaincodeStubInterface) pb.Response  {
-	fmt.Println("########### example_cc Init -- upgrade ###########")
 
-	// test the transient map support with chaincode instantiation
-	tm, err := stub.GetTransient()
-	if err != nil {
-		return shim.Error("{\"Error\":\"Did not find expected transient map in the proposal}")
-	}
-
-	v, ok := tm["test"]
-	if !ok {
-		return shim.Error("{\"Error\":\"Did not find expected key \"test\" in the transient map of the proposal}")
-	}
+	logger.Info("########### example_cc1 Init ###########")
 
-	return shim.Success(v)
-}
-
-func (t *SimpleChaincode) Query(stub shim.ChaincodeStubInterface) pb.Response {
-	return shim.Error("Unknown supported call")
+	// test the transient map support with chaincode instantiation
+	return t.testTransient(stub)
 }
 
 // Transaction makes payment of X units from A to B
 func (t *SimpleChaincode) Invoke(stub shim.ChaincodeStubInterface) pb.Response {
-	fmt.Println("########### example_cc upgrade Invoke ###########")
+	logger.Info("########### example_cc1 Invoke ###########")
 
 	function, args := stub.GetFunctionAndParameters()
 
 	if function != "invoke" {
-                return shim.Error("Unknown function call")
+		return shim.Error("Unknown function call")
 	}
 
 	if len(args) < 2 {
@@ -81,8 +70,10 @@ func (t *SimpleChaincode) Invoke(stub shim.ChaincodeStubInterface) pb.Response {
 		return t.echo(stub, args)
 	}
 	if args[0] == "testTransient" {
-		return t.testTransient(stub, args)
+		return t.testTransient(stub)
 	}
+
+	logger.Errorf("Unknown action: %s, check the first argument, must be one of 'delete', 'query', 'echo', 'testTransient' or 'move'", args[0])
 	return shim.Error(fmt.Sprintf("Unknown action: %s, check the first argument, must be one of 'delete', 'query', 'echo', 'testTransient' or 'move'", args[0]))
 }
 
@@ -127,7 +118,7 @@ func (t *SimpleChaincode) move(stub shim.ChaincodeStubInterface, args []string)
 	}
 	Aval = Aval - X
 	Bval = Bval + X + 10 //new version chaincode gives a bonus 
-	fmt.Printf("Aval = %d, Bval = %d\n", Aval, Bval)
+	logger.Infof("Aval = %d, Bval = %d\n", Aval, Bval)
 
 	// Write the state back to the ledger
 	err = stub.PutState(A, []byte(strconv.Itoa(Aval)))
@@ -185,15 +176,21 @@ func (t *SimpleChaincode) query(stub shim.ChaincodeStubInterface, args []string)
 	}
 
 	jsonResp := "{\"Name\":\"" + A + "\",\"Amount\":\"" + string(Avalbytes) + "\"}"
-	fmt.Printf("Query Response:%s\n", jsonResp)
+	logger.Infof("Query Response:%s\n", jsonResp)
 	return shim.Success(Avalbytes)
 }
 
 // used in SDK test code for transient data support
-func (t *SimpleChaincode) testTransient(stub shim.ChaincodeStubInterface, args []string) pb.Response {
-	tm, _ := stub.GetTransient()
+func (t *SimpleChaincode) testTransient(stub shim.ChaincodeStubInterface) pb.Response {
+	tm, err := stub.GetTransient()
+	if err != nil {
+		logger.Error("Did not find expected transient map in the proposal")
+		return shim.Error("{\"Error\":\"Did not find expected transient map in the proposal}")
+	}
+
 	v, ok := tm["test"]
 	if !ok {
+		logger.Error("Did not find expected key \"test\" in the transient map of the proposal")
 		return shim.Error("{\"Error\":\"Did not find expected key \"test\" in the transient map of the proposal}")
 	}
 
@@ -203,13 +200,13 @@ func (t *SimpleChaincode) testTransient(stub shim.ChaincodeStubInterface, args [
 // Used to return what's in the input for testing purposes
 func (t *SimpleChaincode) echo(stub shim.ChaincodeStubInterface, args []string) pb.Response {
 
-	fmt.Print("Echo Response\n")
+	logger.Info("Echo Response\n")
 	return shim.Success([]byte(args[1]))
 }
 
 func main() {
 	err := shim.Start(new(SimpleChaincode))
 	if err != nil {
-		fmt.Printf("Error starting Simple chaincode: %s", err)
+		logger.Errorf("Error starting Simple chaincode: %s", err)
 	}
 }