Skip to content

Commit

Permalink
[FAB-3560] Endorsement failure doesn't return response
Browse files Browse the repository at this point in the history 
This CR ensures that the response is returned when endorsement fails
due to the chaincode returning an ERROR status (currently, status>=500).
The details in the response, including the status code, message, and
payload from the chaincode are vital pieces of information for
understanding the endorsement failure and acting on it, if necessary.

This CR also adds logging messages that were helpful in debugging the
issue and cleans up a few other logging messages.

Change-Id: I7189c1c5c32e0dd6cd128ec122eefa1841c74ab3
Signed-off-by: Will Lahti <[email protected]>
  • Loading branch information
@wlahti
wlahti committed Jun 2, 2017
1 parent 3b40efa commit 5e49366
Show file tree
Hide file tree
Showing 6 changed files with 212 additions and 16 deletions.
46 changes: 38 additions & 8 deletions core/endorser/endorser.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -80,21 +80,23 @@ func (*Endorser) checkEsccAndVscc(prop *pb.Proposal) error {
func (*Endorser) getTxSimulator(ledgername string) (ledger.TxSimulator, error) {
lgr := peer.GetLedger(ledgername)
if lgr == nil {
return nil, fmt.Errorf("chain does not exist(%s)", ledgername)
return nil, fmt.Errorf("channel does not exist: %s", ledgername)
}
return lgr.NewTxSimulator()
}

func (*Endorser) getHistoryQueryExecutor(ledgername string) (ledger.HistoryQueryExecutor, error) {
lgr := peer.GetLedger(ledgername)
if lgr == nil {
return nil, fmt.Errorf("chain does not exist(%s)", ledgername)
return nil, fmt.Errorf("channel does not exist: %s", ledgername)
}
return lgr.NewHistoryQueryExecutor()
}

//call specified chaincode (system or user)
func (e *Endorser) callChaincode(ctxt context.Context, chainID string, version string, txid string, signedProp *pb.SignedProposal, prop *pb.Proposal, cis *pb.ChaincodeInvocationSpec, cid *pb.ChaincodeID, txsim ledger.TxSimulator) (*pb.Response, *pb.ChaincodeEvent, error) {
endorserLogger.Debugf("Entry - txid: %s channel id: %s version: %s", txid, chainID, version)
defer endorserLogger.Debugf("Exit")
var err error
var res *pb.Response
var ccevent *pb.ChaincodeEvent
Expand All @@ -117,9 +119,8 @@ func (e *Endorser) callChaincode(ctxt context.Context, chainID string, version s
//per doc anything < 500 can be sent as TX.
//fabric errors will always be >= 500 (ie, unambiguous errors )
//"lscc" will respond with status 200 or >=500 (ie, unambiguous OK or ERROR)
//This leaves all < 500 errors to user chaincodes
if res.Status >= shim.ERROR {
return nil, nil, fmt.Errorf(string(res.Message))
return res, nil, nil
}

//----- BEGIN - SECTION THAT MAY NEED TO BE DONE IN LSCC ------
Expand Down Expand Up @@ -200,6 +201,8 @@ func (e *Endorser) disableJavaCCInst(cid *pb.ChaincodeID, cis *pb.ChaincodeInvoc

//simulate the proposal by calling the chaincode
func (e *Endorser) simulateProposal(ctx context.Context, chainID string, txid string, signedProp *pb.SignedProposal, prop *pb.Proposal, cid *pb.ChaincodeID, txsim ledger.TxSimulator) (*ccprovider.ChaincodeData, *pb.Response, []byte, *pb.ChaincodeEvent, error) {
endorserLogger.Debugf("Entry - txid: %s channel id: %s", txid, chainID)
defer endorserLogger.Debugf("Exit")
//we do expect the payload to be a ChaincodeInvocationSpec
//if we are supporting other payloads in future, this be glaringly point
//as something that should change
Expand Down Expand Up @@ -263,6 +266,7 @@ func (e *Endorser) simulateProposal(ctx context.Context, chainID string, txid st
var ccevent *pb.ChaincodeEvent
res, ccevent, err = e.callChaincode(ctx, chainID, version, txid, signedProp, prop, cis, cid, txsim)
if err != nil {
endorserLogger.Errorf("callChaincode() failed for txid: %s error: %s", txid, err)
return nil, nil, nil, nil, err
}

Expand All @@ -286,7 +290,8 @@ func (e *Endorser) getCDSFromLSCC(ctx context.Context, chainID string, txid stri

//endorse the proposal by calling the ESCC
func (e *Endorser) endorseProposal(ctx context.Context, chainID string, txid string, signedProp *pb.SignedProposal, proposal *pb.Proposal, response *pb.Response, simRes []byte, event *pb.ChaincodeEvent, visibility []byte, ccid *pb.ChaincodeID, txsim ledger.TxSimulator, cd *ccprovider.ChaincodeData) (*pb.ProposalResponse, error) {
endorserLogger.Debugf("endorseProposal starts for chainID %s, ccid %s", chainID, ccid)
endorserLogger.Debugf("Entry - txid: %s channel id: %s chaincode id: %s", txid, chainID, ccid)
defer endorserLogger.Debugf("Exit")

isSysCC := cd == nil
// 1) extract the name of the escc that is requested to endorse this chaincode
Expand All @@ -303,7 +308,7 @@ func (e *Endorser) endorseProposal(ctx context.Context, chainID string, txid str
}
}

endorserLogger.Debugf("endorseProposal info: escc for cid %s is %s", ccid, escc)
endorserLogger.Debugf("info: escc for chaincode id %s is %s", ccid, escc)

// marshalling event bytes
var err error
Expand Down Expand Up @@ -353,7 +358,7 @@ func (e *Endorser) endorseProposal(ctx context.Context, chainID string, txid str
}

if res.Status >= shim.ERROR {
return nil, fmt.Errorf(string(res.Message))
return &pb.ProposalResponse{Response: res}, nil
}

prBytes := res.Payload
Expand All @@ -377,6 +382,8 @@ func (e *Endorser) endorseProposal(ctx context.Context, chainID string, txid str

// ProcessProposal process the Proposal
func (e *Endorser) ProcessProposal(ctx context.Context, signedProp *pb.SignedProposal) (*pb.ProposalResponse, error) {
endorserLogger.Debugf("Entry")
defer endorserLogger.Debugf("Exit")
// at first, we check whether the message is valid
prop, hdr, hdrExt, err := validation.ValidateProposalMessage(signedProp)
if err != nil {
Expand All @@ -395,7 +402,7 @@ func (e *Endorser) ProcessProposal(ctx context.Context, signedProp *pb.SignedPro

// block invocations to security-sensitive system chaincodes
if syscc.IsSysCCAndNotInvokableExternal(hdrExt.ChaincodeId.Name) {
endorserLogger.Errorf("ProcessProposal error: an attempt was made by %#v to invoke system chaincode %s",
endorserLogger.Errorf("Error: an attempt was made by %#v to invoke system chaincode %s",
shdr.Creator, hdrExt.ChaincodeId.Name)
err = fmt.Errorf("Chaincode %s cannot be invoked through a proposal", hdrExt.ChaincodeId.Name)
return &pb.ProposalResponse{Response: &pb.Response{Status: 500, Message: err.Error()}}, err
Expand Down Expand Up @@ -468,6 +475,23 @@ func (e *Endorser) ProcessProposal(ctx context.Context, signedProp *pb.SignedPro
if err != nil {
return &pb.ProposalResponse{Response: &pb.Response{Status: 500, Message: err.Error()}}, err
}
if res != nil {
if res.Status >= shim.ERROR {
endorserLogger.Debugf("simulateProposal() resulted in chaincode error for txid: %s", txid)
var cceventBytes []byte
if ccevent != nil {
cceventBytes, err = putils.GetBytesChaincodeEvent(ccevent)
if err != nil {
return nil, fmt.Errorf("failed to marshal event bytes - %s", err)
}
}
pResp, err := putils.CreateProposalResponseFailure(prop.Header, prop.Payload, res, simulationResult, cceventBytes, hdrExt.ChaincodeId, hdrExt.PayloadVisibility)
if err != nil {
return &pb.ProposalResponse{Response: &pb.Response{Status: 500, Message: err.Error()}}, err
}
return pResp, nil
}
}

//2 -- endorse and get a marshalled ProposalResponse message
var pResp *pb.ProposalResponse
Expand All @@ -481,6 +505,12 @@ func (e *Endorser) ProcessProposal(ctx context.Context, signedProp *pb.SignedPro
if err != nil {
return &pb.ProposalResponse{Response: &pb.Response{Status: 500, Message: err.Error()}}, err
}
if pResp != nil {
if res.Status >= shim.ERROR {
endorserLogger.Debugf("endorseProposal() resulted in chaincode error for txid: %s", txid)
return pResp, nil
}
}
}

// Set the proposal response payload - it
Expand Down
21 changes: 17 additions & 4 deletions core/endorser/endorser_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -51,6 +51,8 @@ import (
"github.com/spf13/viper"
"golang.org/x/net/context"
"google.golang.org/grpc"

"github.com/stretchr/testify/assert"
"google.golang.org/grpc/credentials"
)

Expand Down Expand Up @@ -477,7 +479,21 @@ func TestDeployAndInvoke(t *testing.T) {
return
}

fmt.Printf("Invoke test passed\n")
// Test chaincode endorsement failure when invalid function name supplied
f = "invokeinvalid"
invokeArgs = append([]string{f}, args...)
spec = &pb.ChaincodeSpec{Type: 1, ChaincodeId: chaincodeID, Input: &pb.ChaincodeInput{Args: util.ToChaincodeArgs(invokeArgs...)}}
prop, resp, txid, nonce, err = invoke(chainID, spec)
if err != nil {
t.Fail()
t.Logf("Error invoking transaction: %s", err)
chaincode.GetChain().Stop(ctxt, cccid, &pb.ChaincodeDeploymentSpec{ChaincodeSpec: &pb.ChaincodeSpec{ChaincodeId: chaincodeID}})
return
}
if resp != nil {
assert.Equal(t, int32(500), resp.Response.Status, "Unexpected response status")
}

t.Logf("Invoke test passed")

chaincode.GetChain().Stop(ctxt, cccid, &pb.ChaincodeDeploymentSpec{ChaincodeSpec: &pb.ChaincodeSpec{ChaincodeId: chaincodeID}})
Expand Down Expand Up @@ -535,7 +551,6 @@ func TestDeployAndUpgrade(t *testing.T) {
return
}

fmt.Printf("Upgrade test passed\n")
t.Logf("Upgrade test passed")

chaincode.GetChain().Stop(ctxt, cccid1, &pb.ChaincodeDeploymentSpec{ChaincodeSpec: &pb.ChaincodeSpec{ChaincodeId: chaincodeID1}})
Expand Down Expand Up @@ -602,7 +617,6 @@ func TestWritersACLFail(t *testing.T) {
return
}

fmt.Println("TestWritersACLFail passed")
t.Logf("TestWritersACLFail passed")

chaincode.GetChain().Stop(ctxt, cccid, &pb.ChaincodeDeploymentSpec{ChaincodeSpec: &pb.ChaincodeSpec{ChaincodeId: chaincodeID}})
Expand Down Expand Up @@ -647,7 +661,6 @@ func TestAdminACLFail(t *testing.T) {
return
}

fmt.Println("TestAdminACLFail passed")
t.Logf("TestATestAdminACLFailCLFail passed")

chaincode.GetChain().Stop(ctxt, cccid, &pb.ChaincodeDeploymentSpec{ChaincodeSpec: &pb.ChaincodeSpec{ChaincodeId: chaincodeID}})
Expand Down
21 changes: 19 additions & 2 deletions peer/chaincode/common.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,7 @@ import (
"github.com/hyperledger/fabric/common/cauthdsl"
"github.com/hyperledger/fabric/core/chaincode"
"github.com/hyperledger/fabric/core/chaincode/platforms"
"github.com/hyperledger/fabric/core/chaincode/shim"
"github.com/hyperledger/fabric/core/container"
"github.com/hyperledger/fabric/msp"
"github.com/hyperledger/fabric/peer/common"
Expand Down Expand Up @@ -104,11 +105,24 @@ func chaincodeInvokeOrQuery(cmd *cobra.Command, args []string, invoke bool, cf *
proposalResp, err := ChaincodeInvokeOrQuery(spec, chainID, invoke,
cf.Signer, cf.EndorserClient, cf.BroadcastClient)
if err != nil {
return err
return fmt.Errorf("%s - %v", err, proposalResp)
}

if invoke {
logger.Infof("Invoke result: %v", proposalResp)
if proposalResp.Response.Status >= shim.ERROR {
logger.Debugf("ESCC invoke result: %v", proposalResp)
pRespPayload, err := putils.GetProposalResponsePayload(proposalResp.Payload)
if err != nil {
return fmt.Errorf("Error while unmarshaling proposal response payload: %s", err)
}
ca, err := putils.GetChaincodeAction(pRespPayload.Extension)
if err != nil {
return fmt.Errorf("Error while unmarshaling chaincode action: %s", err)
}
logger.Warningf("Endorsement failure during invoke. chaincode result: %v", ca.Response)
} else {
logger.Infof("Invoke result: %v", proposalResp)
}
} else {
if proposalResp == nil {
return fmt.Errorf("Error query %s by endorsing: %s", chainFuncName, err)
Expand Down Expand Up @@ -309,6 +323,9 @@ func ChaincodeInvokeOrQuery(spec *pb.ChaincodeSpec, cID string, invoke bool,

if invoke {
if proposalResp != nil {
if proposalResp.Response.Status >= shim.ERROR {
return proposalResp, nil
}
// assemble a signed transaction (it's an Envelope message)
env, err := putils.CreateSignedTx(prop, signer, proposalResp)
if err != nil {
Expand Down
79 changes: 78 additions & 1 deletion peer/chaincode/invoke_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -17,12 +17,19 @@
package chaincode

import (
"bytes"
"errors"
"fmt"
"testing"

"github.com/hyperledger/fabric/common/flogging"
"github.com/hyperledger/fabric/common/util"
"github.com/hyperledger/fabric/msp"
"github.com/hyperledger/fabric/peer/common"
cb "github.com/hyperledger/fabric/protos/common"
pb "github.com/hyperledger/fabric/protos/peer"
"github.com/hyperledger/fabric/protos/utils"
logging "github.com/op/go-logging"
"github.com/stretchr/testify/assert"
)

Expand Down Expand Up @@ -116,7 +123,7 @@ func TestInvokeCmd(t *testing.T) {
assert.NoError(t, err)
}

func TestInvokeCmdEndorseFail(t *testing.T) {
func TestInvokeCmdEndorsementError(t *testing.T) {
InitMSP()
mockCF, err := getMockChaincodeCmdFactoryWithErr()
assert.NoError(t, err, "Error getting mock chaincode command factory")
Expand All @@ -130,6 +137,35 @@ func TestInvokeCmdEndorseFail(t *testing.T) {
assert.Error(t, err, "Expected error executing invoke command")
}

func TestInvokeCmdEndorsementFailure(t *testing.T) {
InitMSP()
ccRespStatus := int32(502)
ccRespPayload := []byte("Invalid function name")
mockCF, err := getMockChaincodeCmdFactoryEndorsementFailure(ccRespStatus, ccRespPayload)
assert.NoError(t, err, "Error getting mock chaincode command factory")

cmd := invokeCmd(mockCF)
AddFlags(cmd)
args := []string{"-n", "example02", "-p", "github.com/hyperledger/fabric/examples/chaincode/go/chaincode_example02",
"-c", "{\"Args\": [\"invokeinvalid\",\"a\",\"b\",\"10\"]}"}
cmd.SetArgs(args)

// set logger to logger with a backend that writes to a byte buffer
var buffer bytes.Buffer
logger.SetBackend(logging.AddModuleLevel(logging.NewLogBackend(&buffer, "", 0)))
// reset the logger after test
defer func() {
flogging.Reset()
}()
// make sure buffer is "clean" before running the invoke
buffer.Reset()

err = cmd.Execute()
assert.NoError(t, err)
assert.Regexp(t, "Endorsement failure during invoke", buffer.String())
assert.Regexp(t, fmt.Sprintf("chaincode result: status:%d payload:\"%s\"", ccRespStatus, ccRespPayload), buffer.String())
}

// Returns mock chaincode command factory
func getMockChaincodeCmdFactory() (*ChaincodeCmdFactory, error) {
signer, err := common.GetDefaultSigner()
Expand Down Expand Up @@ -169,3 +205,44 @@ func getMockChaincodeCmdFactoryWithErr() (*ChaincodeCmdFactory, error) {
}
return mockCF, nil
}

// Returns mock chaincode command factory
func getMockChaincodeCmdFactoryEndorsementFailure(ccRespStatus int32, ccRespPayload []byte) (*ChaincodeCmdFactory, error) {
signer, err := common.GetDefaultSigner()
if err != nil {
return nil, err
}

// create a proposal from a ChaincodeInvocationSpec
prop, _, err := utils.CreateChaincodeProposal(cb.HeaderType_ENDORSER_TRANSACTION, util.GetTestChainID(), createCIS(), nil)
if err != nil {
return nil, fmt.Errorf("Could not create chaincode proposal, err %s\n", err)
}

response := &pb.Response{Status: ccRespStatus, Payload: ccRespPayload}
result := []byte("res")
ccid := &pb.ChaincodeID{Name: "foo", Version: "v1"}

mockRespFailure, err := utils.CreateProposalResponseFailure(prop.Header, prop.Payload, response, result, nil, ccid, nil)
if err != nil {

return nil, fmt.Errorf("Could not create proposal response failure, err %s\n", err)
}

mockEndorserClient := common.GetMockEndorserClient(mockRespFailure, nil)
mockBroadcastClient := common.GetMockBroadcastClient(nil)
mockCF := &ChaincodeCmdFactory{
EndorserClient: mockEndorserClient,
Signer: signer,
BroadcastClient: mockBroadcastClient,
}
return mockCF, nil
}

func createCIS() *pb.ChaincodeInvocationSpec {
return &pb.ChaincodeInvocationSpec{
ChaincodeSpec: &pb.ChaincodeSpec{
Type: pb.ChaincodeSpec_GOLANG,
ChaincodeId: &pb.ChaincodeID{Name: "chaincode_name"},
Input: &pb.ChaincodeInput{Args: [][]byte{[]byte("arg1"), []byte("arg2")}}}}
}
31 changes: 30 additions & 1 deletion protos/utils/txutils.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -225,7 +225,7 @@ func CreateProposalResponse(hdrbytes []byte, payl []byte, response *peer.Respons
// get the bytes of the proposal response payload - we need to sign them
prpBytes, err := GetBytesProposalResponsePayload(pHashBytes, response, results, events, ccid)
if err != nil {
return nil, errors.New("Failure while unmarshalling the ProposalResponsePayload")
return nil, errors.New("Failure while marshaling the ProposalResponsePayload")
}

// serialize the signing identity
Expand All @@ -250,6 +250,35 @@ func CreateProposalResponse(hdrbytes []byte, payl []byte, response *peer.Respons
return resp, nil
}

// CreateProposalResponseFailure creates a proposal response for cases where
// endorsement proposal fails either due to a endorsement failure or a chaincode
// failure (chaincode response status >=500)
func CreateProposalResponseFailure(hdrbytes []byte, payl []byte, response *peer.Response, results []byte, events []byte, ccid *peer.ChaincodeID, visibility []byte) (*peer.ProposalResponse, error) {
hdr, err := GetHeader(hdrbytes)
if err != nil {
return nil, err
}

// obtain the proposal hash given proposal header, payload and the requested visibility
pHashBytes, err := GetProposalHash1(hdr, payl, visibility)
if err != nil {
return nil, fmt.Errorf("Could not compute proposal hash: err %s", err)
}

// get the bytes of the proposal response payload
prpBytes, err := GetBytesProposalResponsePayload(pHashBytes, response, results, events, ccid)
if err != nil {
return nil, errors.New("Failure while marshaling the ProposalResponsePayload")
}

resp := &peer.ProposalResponse{
// Timestamp: TODO!
Payload: prpBytes,
Response: &peer.Response{Status: 500, Message: "Chaincode Error"}}

return resp, nil
}

// GetSignedProposal returns a signed proposal given a Proposal message and a signing identity
func GetSignedProposal(prop *peer.Proposal, signer msp.SigningIdentity) (*peer.SignedProposal, error) {
// check for nil argument
Expand Down
Loading

0 comments on commit 5e49366

Please sign in to comment.