1. Messages
  2. Inconsistent Private Data Collection Write operation

Re: Inconsistent Private Data Collection Write operation

Hritik Gupta <hritikgupta9@...>
 

I have attached the screenshots of the logs from Org1 peer container for your reference, for better readability. 

Logs when it worked:
2020-06-19 12:49:09.580 UTC [comm.grpc.server] 1 -> INFO 122 unary call completed grpc.service=discovery.Discovery grpc.method=Discover grpc.peer_address=192.168.112.1:57578 grpc.peer_subject="CN=fabric-common" grpc.code=OK grpc.call_duration=679.842µs
2020-06-19 12:49:09.608 UTC [comm.grpc.server] 1 -> INFO 123 unary call completed grpc.service=discovery.Discovery grpc.method=Discover grpc.peer_address=192.168.112.1:57578 grpc.peer_subject="CN=fabric-common" grpc.code=OK grpc.call_duration=813.325µs
2020-06-19 12:49:09.622 UTC [endorser] callChaincode -> INFO 124 finished chaincode: fabcar duration: 1ms channel=mychannel txID=de27f4ec
2020-06-19 12:49:09.635 UTC [comm.grpc.server] 1 -> INFO 125 unary call completed grpc.service=protos.Endorser grpc.method=ProcessProposal grpc.peer_address=192.168.112.1:57586 grpc.peer_subject="CN=fabric-common" grpc.code=OK grpc.call_duration=14.715518ms
2020-06-19 12:49:11.678 UTC [gossip.privdata] StoreBlock -> INFO 126 [mychannel] Received block [20] from buffer
2020-06-19 12:49:11.680 UTC [committer.txvalidator] Validate -> INFO 127 [mychannel] Validated block [20] in 2ms
2020-06-19 12:49:11.681 UTC [gossip.privdata] prepareBlockPvtdata -> INFO 128 Successfully fetched all eligible collection private write sets for block [20] channel=mychannel
2020-06-19 12:49:11.712 UTC [kvledger] CommitLegacy -> INFO 129 [mychannel] Committed block [20] with 1 transaction(s) in 30ms (state_validation=0ms block_and_pvtdata_commit=18ms state_commit=5ms) commitHash=[6bfa36ced7abf414a278943a0efe5cc5bbbfeecb9ef5edce84b862e314b688c4]
2020-06-19 12:49:11.723 UTC [comm.grpc.server] 1 -> INFO 12a streaming call completed grpc.service=protos.Deliver grpc.method=DeliverFiltered grpc.peer_address=192.168.112.1:57594 grpc.peer_subject="CN=fabric-common" error="context finished before block retrieved: context canceled" grpc.code=Unknown grpc.call_duration=2.075316216s

Logs when it failed:
2020-06-19 12:45:31.198 UTC [comm.grpc.server] 1 -> INFO 0ea unary call completed grpc.service=discovery.Discovery grpc.method=Discover grpc.peer_address=192.168.112.1:57492 grpc.peer_subject="CN=fabric-common" grpc.code=OK grpc.call_duration=805.632µs
2020-06-19 12:45:31.224 UTC [comm.grpc.server] 1 -> INFO 0eb unary call completed grpc.service=discovery.Discovery grpc.method=Discover grpc.peer_address=192.168.112.1:57492 grpc.peer_subject="CN=fabric-common" grpc.code=OK grpc.call_duration=757.737µs
2020-06-19 12:45:31.238 UTC [endorser] callChaincode -> INFO 0ec finished chaincode: fabcar duration: 1ms channel=mychannel txID=ee3f5ebe
2020-06-19 12:45:31.775 UTC [comm.grpc.server] 1 -> INFO 0ed unary call completed grpc.service=protos.Endorser grpc.method=ProcessProposal grpc.peer_address=192.168.112.1:57500 grpc.peer_subject="CN=fabric-common" grpc.code=OK grpc.call_duration=539.382571ms
2020-06-19 12:45:35.051 UTC [gossip.privdata] StoreBlock -> INFO 0ee [mychannel] Received block [16] from buffer
2020-06-19 12:45:35.053 UTC [policies] SignatureSetToValidIdentities -> WARN 0ef signature for identity 0 is invalid: The signature is invalid
2020-06-19 12:45:35.054 UTC [policies] SignatureSetToValidIdentities -> WARN 0f0 signature for identity 0 is invalid: The signature is invalid
2020-06-19 12:45:35.054 UTC [vscc] Validate -> ERRO 0f1 VSCC error: stateBasedValidator.Validate failed, err validation of endorsement policy for chaincode fabcar in tx 16:0 failed: implicit policy evaluation failed - 0 sub-policies were satisfied, but this policy requires 2 of the 'Endorsement' sub-policies to be satisfied
2020-06-19 12:45:35.054 UTC [committer.txvalidator] validateTx -> ERRO 0f2 Dispatch for transaction txId = ee3f5ebe9aee21b245ef1ceb376e0e8facfd0b71965c2defae37d5a70b3558db returned error: validation of endorsement policy for chaincode fabcar in tx 16:0 failed: implicit policy evaluation failed - 0 sub-policies were satisfied, but this policy requires 2 of the 'Endorsement' sub-policies to be satisfied
2020-06-19 12:45:35.054 UTC [committer.txvalidator] Validate -> INFO 0f3 [mychannel] Validated block [16] in 3ms
2020-06-19 12:45:35.054 UTC [gossip.privdata] prepareBlockPvtdata -> INFO 0f4 Successfully fetched all eligible collection private write sets for block [16] channel=mychannel
2020-06-19 12:45:35.055 UTC [valimpl] preprocessProtoBlock -> WARN 0f5 Channel [mychannel]: Block [16] Transaction index [0] TxId [ee3f5ebe9aee21b245ef1ceb376e0e8facfd0b71965c2defae37d5a70b3558db] marked as invalid by committer. Reason code [ENDORSEMENT_POLICY_FAILURE]
2020-06-19 12:45:36.879 UTC [kvledger] CommitLegacy -> INFO 0f6 [mychannel] Committed block [16] with 1 transaction(s) in 1824ms (state_validation=0ms block_and_pvtdata_commit=1075ms state_commit=363ms) commitHash=[0caec1920f414394bd085c351bf04c66b18ee0d67c9d7313687b9216e79261d5]
2020-06-19 12:45:36.893 UTC [comm.grpc.server] 1 -> INFO 0f7 streaming call completed grpc.service=protos.Deliver grpc.method=DeliverFiltered grpc.peer_address=192.168.112.1:57508 grpc.peer_subject="CN=fabric-common" error="context finished before block retrieved: context canceled" grpc.code=Unknown grpc.call_duration=5.099824363s

@email4tong : I tried deploying the chaincode with this policy, it gave me an Error: invalid collection configuration: invalid endorsement policy. 

Thanks.

On Fri, Jun 19, 2020 at 6:05 PM email4tong@... <email4tong@...> wrote:
Curious about this policy,

"endorsementPolicy": { "signaturePolicy": "OR('Org1MSP.member'), OR('Org2MSP.member')" }


was it accepted as a valid policy? if it was accepted, should this be a bug? what does this policy exactly mean? Is it the same as this

"endorsementPolicy": {
      "signaturePolicy": "OR('Org1MSP.member', 'Org2MSP.member')"
    }

Thanks.

On Friday, June 19, 2020, 8:29:10 AM EDT, David Enyeart <enyeart@...> wrote:


The endorsement policy check only checks which peers have endorsed, not which clients have submitted the transaction. The peer validation logic is deterministic in this regard.
Could you share the Org1 peer log showing it working once, and not working once, with no other changes inbetween? Please highlight the log timestamp of endorsement and validation in both cases.


Thanks,

Dave Enyeart

"Hritik Gupta" ---06/19/2020 08:11:18 AM---I ran the network again, to double check. The inconsistency issue still exists. The issue occurs eve

From: "Hritik Gupta" <hritikgupta9@...>
To: Cendhu U <cendhu@...>
Cc: fabric <fabric@...>
Date: 06/19/2020 08:11 AM
Subject: [EXTERNAL] Re: [Hyperledger Fabric] Inconsistent Private Data Collection Write operation
Sent by: fabric@...




I ran the network again, to double check. The inconsistency issue still exists. The issue occurs even when I pass OR("Org1MSP.Member") as the EP and try to update the key via Org1 client (which is an authorized peer).



On Fri, Jun 19, 2020 at 5:31 PM Cendhu U <cendhu@...> wrote:
    but this policy requires 2 of the 'Endorsement' sub-policies to be satisfied

      the above error seems to match your old definition -- "endorsementPolicy": { "signaturePolicy": "OR('Org1MSP.member'), OR('Org2MSP.member')" }

      Anyway, I do not have expertise in this. If Yacov looks at this message, he might clarify.

      Regards,
      Senthil

      On Fri, Jun 19, 2020 at 5:21 PM Hritik Gupta <hritikgupta9@...> wrote:
      Sorry for typing it wrong. The endorsement policy in my collections config is as follows:

      "endorsementPolicy": {
            "signaturePolicy": "OR('Org1MSP.member', 'Org2MSP.member')"
          }

      Setting memberOnlyWrite to false is deliberate because I want the peers of only Org2 and Org1 to be able to write to the private data collection; and not any other Org that might join the network in future. 


      -- 








      Join fabric@lists.hyperledger.org to automatically receive all group messages.