hyperledger / fabric-sdk-node

Hyperledger Fabric SDK for Node https://wiki.hyperledger.org/display/fabric
https://hyperledger.github.io/fabric-sdk-node/
Apache License 2.0
793 stars 516 forks source link

incomplete discovery information can be returned when the node-sdk 2.2.13 is under load #601

Closed davidkel closed 2 years ago

davidkel commented 2 years ago

When using Caliper to drive the node sdk 2.2 which sends out multiple concurrent endorsement some of the initial endorsements fail with the error

2022.06.29-14:04:17.120 error [caliper] [connectors/v2/FabricGateway]   Failed to perform submit transaction [createAsset] using arguments [client1_100_2,{"docType":"fixed-asset","content":"BBBBBBBBBBBBBBBBBBBBBBBBBBB","creator":"client1","byteSize":100,"uuid":"client1_100_2"}],  with error: Error: No endorsement plan available
    at DiscoveryHandler.endorse (/home/ubuntu/caliper-benchmarks/node_modules/fabric-network/node_modules/fabric-common/lib/DiscoveryHandler.js:213:10)
    at processTicksAndRejections (internal/process/task_queues.js:95:5)
    at async Endorsement.send (/home/ubuntu/caliper-benchmarks/node_modules/fabric-network/node_modules/fabric-common/lib/Proposal.js:409:15)
    at async Transaction.submit (/home/ubuntu/caliper-benchmarks/node_modules/fabric-network/lib/transaction.js:253:34)
    at async V2FabricGateway._submitOrEvaluateTransaction (/home/ubuntu/caliper-benchmarks/node_modules/@hyperledger/caliper-fabric/lib/connector-versions/v2/FabricGateway.js:375:26

the call made by DiscoveryHandler line 188

const results = await this.discoveryService.getDiscoveryResults(true);

gets incomplete results because the discovery information is still being processed to build up the complete discovery results.

The result we get back looks like this

results {
  msps: {
    OrdererMSP: {
      id: 'OrdererMSP',
      name: 'OrdererMSP',
      organizationalUnitIdentifiers: [],
      rootCerts: '-----BEGIN CERTIFICATE-----\n' +

        '-----END CERTIFICATE-----\n',
      intermediateCerts: '',
      admins: '',
      tlsRootCerts: '-----BEGIN CERTIFICATE-----\n' +

        '-----END CERTIFICATE-----\n',
      tlsIntermediateCerts: ''
    },
    Org1MSP: {
      id: 'Org1MSP',
      name: 'Org1MSP',
      organizationalUnitIdentifiers: [],
      rootCerts: '-----BEGIN CERTIFICATE-----\n' +

      intermediateCerts: '',
      admins: '',
      tlsRootCerts: '-----BEGIN CERTIFICATE-----\n' +

        '-----END CERTIFICATE-----\n',
      tlsIntermediateCerts: ''
    },
    Org2MSP: {
      id: 'Org2MSP',
      name: 'Org2MSP',
      organizationalUnitIdentifiers: [],
      rootCerts: '-----BEGIN CERTIFICATE-----\n' +

        '-----END CERTIFICATE-----\n',
      intermediateCerts: '',
      admins: '',
      tlsRootCerts: '-----BEGIN CERTIFICATE-----\n' +
        '-----END CERTIFICATE-----\n',
      tlsIntermediateCerts: ''
    }
  },
  orderers: { OrdererMSP: { endpoints: [Array] } 
}

so at this point it is missing the complete discovery results (especially the timestamp). The complete discovery results should also contain after the orderers property

  peers_by_org: { Org1MSP: { peers: [Array] }, Org2MSP: { peers: [Array] } },
  endorsement_plan: {
    chaincode: 'fixed-asset',
    groups: { G0: [Object], G1: [Object] },
    layouts: [ [Object] ]
  },
  timestamp: 1656515912508

looking at the getDiscoveryResults code (logging lines removed)

    async getDiscoveryResults(refresh) {
        if (!this.discoveryResults && !this.savedResults) {
            throw Error('No discovery results found');
        }
        // when savedResults exist, then a refresh is running
        if (this.savedResults) {
            logger.debug(`${method} - using the saved results`);
            return this.savedResults;
        }

        if (refresh && (new Date()).getTime() - this.discoveryResults.timestamp > this.refreshAge) {
            this.savedResults = this.discoveryResults;
            await this.send({asLocalhost: this.asLocalhost, requestTimeout: this.requestTimeout, targets: this.targets});
            this.savedResults = null;
        } 
        return this.discoveryResults;
    }

we see that a call will return the contents of this.discoveryResults (it doesn't return savedResults because there aren't any at this point) but it could still be being updated by the this.send call still executing from another caller because it first sets this.discoveryResults to {} but then fills in the contents are it parses the results (and each section that is built up is an async call) so the update hasn't finished populating the results that get returned because it allows other async code to execute in-between it populating the discovery results

With refresh set to true it won't drop into performing a send because with no timestamp currently set the result of the if statement will be false because new Date()).getTime() - this.discoveryResults.timestamp results in NaN which protects from multiple calls trying to perform a send and update on this.discoveryResults at the same time.

the use of this.discoveryResults is prolific within the methods called to update the discoveryResults and not limited to the send method itself

davidkel commented 2 years ago

A further point is I believe the initiation of building the initial discovery results are done by the gateway api as it has a couple of places where it invokes send on DiscoveryService