2017-11-24 11:05:27.682 UTC [orderer/main] main -> INFO 001 Starting orderer: Version: 1.0.0 Go version: go1.7.5 OS/Arch: linux/amd64 2017-11-24 11:05:27.686 UTC [orderer/main] initializeSecureServerConfig -> INFO 002 Starting orderer with TLS enabled 2017-11-24 11:05:27.747 UTC [bccsp_sw] openKeyStore -> DEBU 003 KeyStore opened at [/var/hyperledger/orderer/msp/keystore]...done 2017-11-24 11:05:27.748 UTC [bccsp] initBCCSP -> DEBU 004 Initialize BCCSP [SW] 2017-11-24 11:05:27.748 UTC [msp] getPemMaterialFromDir -> DEBU 005 Reading directory /var/hyperledger/orderer/msp/signcerts 2017-11-24 11:05:27.759 UTC [msp] getPemMaterialFromDir -> DEBU 006 Inspecting file /var/hyperledger/orderer/msp/signcerts/orderer2.orgorderer1-cert.pem 2017-11-24 11:05:27.768 UTC [msp] getPemMaterialFromDir -> DEBU 007 Reading directory /var/hyperledger/orderer/msp/cacerts 2017-11-24 11:05:27.779 UTC [msp] getPemMaterialFromDir -> DEBU 008 Inspecting file /var/hyperledger/orderer/msp/cacerts/ca.orgorderer1-cert.pem 2017-11-24 11:05:27.787 UTC [msp] getPemMaterialFromDir -> DEBU 009 Reading directory /var/hyperledger/orderer/msp/admincerts 2017-11-24 11:05:27.798 UTC [msp] getPemMaterialFromDir -> DEBU 00a Inspecting file /var/hyperledger/orderer/msp/admincerts/Admin@orgorderer1-cert.pem 2017-11-24 11:05:27.807 UTC [msp] getPemMaterialFromDir -> DEBU 00b Reading directory /var/hyperledger/orderer/msp/intermediatecerts 2017-11-24 11:05:27.809 UTC [msp] getMspConfig -> DEBU 00c Intermediate certs folder not found at [/var/hyperledger/orderer/msp/intermediatecerts]. Skipping. [stat /var/hyperledger/orderer/msp/intermediatecerts: no such file or directory] 2017-11-24 11:05:27.809 UTC [msp] getPemMaterialFromDir -> DEBU 00d Reading directory /var/hyperledger/orderer/msp/tlscacerts 2017-11-24 11:05:27.821 UTC [msp] getPemMaterialFromDir -> DEBU 00e Inspecting file /var/hyperledger/orderer/msp/tlscacerts/tlsca.orgorderer1-cert.pem 2017-11-24 11:05:27.829 UTC [msp] getPemMaterialFromDir -> DEBU 00f Reading directory /var/hyperledger/orderer/msp/tlsintermediatecerts 2017-11-24 11:05:27.831 UTC [msp] getMspConfig -> DEBU 010 TLS intermediate certs folder not found at [/var/hyperledger/orderer/msp/tlsintermediatecerts]. Skipping. [stat /var/hyperledger/orderer/msp/tlsintermediatecerts: no such file or directory] 2017-11-24 11:05:27.831 UTC [msp] getPemMaterialFromDir -> DEBU 011 Reading directory /var/hyperledger/orderer/msp/crls 2017-11-24 11:05:27.834 UTC [msp] getMspConfig -> DEBU 012 crls folder not found at [/var/hyperledger/orderer/msp/crls]. Skipping. [stat /var/hyperledger/orderer/msp/crls: no such file or directory] 2017-11-24 11:05:27.836 UTC [msp] getMspConfig -> DEBU 013 MSP configuration file not found at [/var/hyperledger/orderer/msp/config.yaml]: [stat /var/hyperledger/orderer/msp/config.yaml: no such file or directory] 2017-11-24 11:05:27.837 UTC [msp] NewBccspMsp -> DEBU 014 Creating BCCSP-based MSP instance 2017-11-24 11:05:27.837 UTC [msp] GetLocalMSP -> DEBU 015 Created new local MSP 2017-11-24 11:05:27.837 UTC [msp] Setup -> DEBU 016 Setting up MSP instance Orgorderer1MSP 2017-11-24 11:05:27.837 UTC [msp/identity] newIdentity -> DEBU 017 Creating identity instance for ID &{Orgorderer1MSP f879c2ec0ac3215b0a2042a3073b43e0db0f66a60e2c094b1f9b1941273f0d0d} 2017-11-24 11:05:27.837 UTC [msp/identity] newIdentity -> DEBU 018 Creating identity instance for ID &{Orgorderer1MSP 8da4e1d96dad42b4e45a7323b55ddfc8af2280460c23fb4e66b45f4466435299} 2017-11-24 11:05:27.837 UTC [msp/identity] newIdentity -> DEBU 019 Creating identity instance for ID &{Orgorderer1MSP 8da4e1d96dad42b4e45a7323b55ddfc8af2280460c23fb4e66b45f4466435299} 2017-11-24 11:05:27.838 UTC [msp/identity] newIdentity -> DEBU 01a Creating identity instance for ID &{Orgorderer1MSP 1cbf17f7b537f919f5b81b36a0618fb9f22831f12e5de09f9539a1f0e4b91099} 2017-11-24 11:05:27.840 UTC [bccsp_sw] loadPrivateKey -> DEBU 01b Loading private key [c645f0ee931f483238aa17a2b4f7f717e869f98f2f9cf20001902d29d34dd1f1] at [/var/hyperledger/orderer/msp/keystore/c645f0ee931f483238aa17a2b4f7f717e869f98f2f9cf20001902d29d34dd1f1_sk]... 2017-11-24 11:05:27.849 UTC [msp/identity] newIdentity -> DEBU 01c Creating identity instance for ID &{Orgorderer1MSP 1cbf17f7b537f919f5b81b36a0618fb9f22831f12e5de09f9539a1f0e4b91099} 2017-11-24 11:05:27.849 UTC [msp] Validate -> DEBU 01d MSP Orgorderer1MSP validating identity 2017-11-24 11:05:27.849 UTC [orderer/main] createLedgerFactory -> DEBU 01e Ledger dir: /var/hyperledger/production/orderer 2017-11-24 11:05:27.849 UTC [kvledger.util] CreateDirIfMissing -> DEBU 01f CreateDirIfMissing [/var/hyperledger/production/orderer/index/] 2017-11-24 11:05:27.849 UTC [kvledger.util] logDirStatus -> DEBU 020 Before creating dir - [/var/hyperledger/production/orderer/index/] does not exist 2017-11-24 11:05:27.850 UTC [kvledger.util] logDirStatus -> DEBU 021 After creating dir - [/var/hyperledger/production/orderer/index/] exists 2017-11-24 11:05:27.865 UTC [fsblkstorage] newBlockfileMgr -> DEBU 022 newBlockfileMgr() initializing file-based block storage for ledger: testchainid 2017-11-24 11:05:27.865 UTC [kvledger.util] CreateDirIfMissing -> DEBU 023 CreateDirIfMissing [/var/hyperledger/production/orderer/chains/testchainid/] 2017-11-24 11:05:27.865 UTC [kvledger.util] logDirStatus -> DEBU 024 Before creating dir - [/var/hyperledger/production/orderer/chains/testchainid/] does not exist 2017-11-24 11:05:27.865 UTC [kvledger.util] logDirStatus -> DEBU 025 After creating dir - [/var/hyperledger/production/orderer/chains/testchainid/] exists 2017-11-24 11:05:27.867 UTC [fsblkstorage] syncCPInfoFromFS -> DEBU 026 Starting checkpoint=latestFileChunkSuffixNum=[0], latestFileChunksize=[0], isChainEmpty=[true], lastBlockNumber=[0] 2017-11-24 11:05:27.867 UTC [fsblkstorage] syncCPInfoFromFS -> DEBU 027 status of file [/var/hyperledger/production/orderer/chains/testchainid/blockfile_000000]: exists=[false], size=[0] 2017-11-24 11:05:27.867 UTC [fsblkstorage] newBlockIndex -> DEBU 028 newBlockIndex() - indexItems:[[BlockNum]] 2017-11-24 11:05:27.867 UTC [fsblkstorage] newBlockfileStream -> DEBU 029 newBlockfileStream(): filePath=[/var/hyperledger/production/orderer/chains/testchainid/blockfile_000000], startOffset=[0] 2017-11-24 11:05:27.867 UTC [fsblkstorage] nextBlockBytesAndPlacementInfo -> DEBU 02a Finished reading file number [0] 2017-11-24 11:05:27.867 UTC [fsblkstorage] nextBlockBytesAndPlacementInfo -> DEBU 02b blockbytes [0] read from file [0] 2017-11-24 11:05:27.869 UTC [fsblkstorage] indexBlock -> DEBU 02c Indexing block [blockNum=0, blockHash=[]byte{0x48, 0xca, 0xe8, 0xb0, 0xdf, 0x44, 0x77, 0x1f, 0xea, 0xac, 0x3c, 0x20, 0x1a, 0x70, 0x3d, 0x9d, 0x84, 0x57, 0xe8, 0xfa, 0x32, 0x98, 0xb8, 0xa1, 0x86, 0xa6, 0x18, 0x6d, 0xc5, 0xed, 0xcc, 0x7e} txOffsets= txId=c6ab72e89d93b18949e9e225410ba0ee74c8b74a3dfadcfe940994c4eb0f9633 locPointer=offset=38, bytesLength=8841 ] 2017-11-24 11:05:27.869 UTC [fsblkstorage] updateCheckpoint -> DEBU 02d Broadcasting about update checkpointInfo: latestFileChunkSuffixNum=[0], latestFileChunksize=[8884], isChainEmpty=[false], lastBlockNumber=[0] 2017-11-24 11:05:27.869 UTC [fsblkstorage] retrieveBlockByNumber -> DEBU 02e retrieveBlockByNumber() - blockNum = [0] 2017-11-24 11:05:27.869 UTC [fsblkstorage] newBlockfileStream -> DEBU 02f newBlockfileStream(): filePath=[/var/hyperledger/production/orderer/chains/testchainid/blockfile_000000], startOffset=[0] 2017-11-24 11:05:27.869 UTC [fsblkstorage] nextBlockBytesAndPlacementInfo -> DEBU 030 Remaining bytes=[8884], Going to peek [8] bytes 2017-11-24 11:05:27.869 UTC [fsblkstorage] nextBlockBytesAndPlacementInfo -> DEBU 031 Returning blockbytes - length=[8882], placementInfo={fileNum=[0], startOffset=[0], bytesOffset=[2]} 2017-11-24 11:05:27.869 UTC [fsblkstorage] retrieveBlockByNumber -> DEBU 032 retrieveBlockByNumber() - blockNum = [0] 2017-11-24 11:05:27.869 UTC [fsblkstorage] newBlockfileStream -> DEBU 033 newBlockfileStream(): filePath=[/var/hyperledger/production/orderer/chains/testchainid/blockfile_000000], startOffset=[0] 2017-11-24 11:05:27.869 UTC [fsblkstorage] nextBlockBytesAndPlacementInfo -> DEBU 034 Remaining bytes=[8884], Going to peek [8] bytes 2017-11-24 11:05:27.869 UTC [fsblkstorage] nextBlockBytesAndPlacementInfo -> DEBU 035 Returning blockbytes - length=[8882], placementInfo={fileNum=[0], startOffset=[0], bytesOffset=[2]} 2017-11-24 11:05:27.869 UTC [common/config] NewStandardValues -> DEBU 036 Initializing protos for *config.ChannelProtos 2017-11-24 11:05:27.869 UTC [common/config] initializeProtosStruct -> DEBU 037 Processing field: HashingAlgorithm 2017-11-24 11:05:27.869 UTC [common/config] initializeProtosStruct -> DEBU 038 Processing field: BlockDataHashingStructure 2017-11-24 11:05:27.869 UTC [common/config] initializeProtosStruct -> DEBU 039 Processing field: OrdererAddresses 2017-11-24 11:05:27.869 UTC [common/config] initializeProtosStruct -> DEBU 03a Processing field: Consortium 2017-11-24 11:05:27.870 UTC [common/configtx] addToMap -> DEBU 03b Adding to config map: [Groups] /Channel 2017-11-24 11:05:27.870 UTC [common/configtx] addToMap -> DEBU 03c Adding to config map: [Groups] /Channel/Consortiums 2017-11-24 11:05:27.870 UTC [common/configtx] addToMap -> DEBU 03d Adding to config map: [Groups] /Channel/Consortiums/SampleConsortium 2017-11-24 11:05:27.870 UTC [common/configtx] addToMap -> DEBU 03e Adding to config map: [Groups] /Channel/Consortiums/SampleConsortium/Org2MSP 2017-11-24 11:05:27.870 UTC [common/configtx] addToMap -> DEBU 03f Adding to config map: [Values] /Channel/Consortiums/SampleConsortium/Org2MSP/MSP 2017-11-24 11:05:27.870 UTC [common/configtx] addToMap -> DEBU 040 Adding to config map: [Policy] /Channel/Consortiums/SampleConsortium/Org2MSP/Writers 2017-11-24 11:05:27.870 UTC [common/configtx] addToMap -> DEBU 041 Adding to config map: [Policy] /Channel/Consortiums/SampleConsortium/Org2MSP/Admins 2017-11-24 11:05:27.870 UTC [common/configtx] addToMap -> DEBU 042 Adding to config map: [Policy] /Channel/Consortiums/SampleConsortium/Org2MSP/Readers 2017-11-24 11:05:27.870 UTC [common/configtx] addToMap -> DEBU 043 Adding to config map: [Groups] /Channel/Consortiums/SampleConsortium/Org1MSP 2017-11-24 11:05:27.870 UTC [common/configtx] addToMap -> DEBU 044 Adding to config map: [Values] /Channel/Consortiums/SampleConsortium/Org1MSP/MSP 2017-11-24 11:05:27.870 UTC [common/configtx] addToMap -> DEBU 045 Adding to config map: [Policy] /Channel/Consortiums/SampleConsortium/Org1MSP/Readers 2017-11-24 11:05:27.870 UTC [common/configtx] addToMap -> DEBU 046 Adding to config map: [Policy] /Channel/Consortiums/SampleConsortium/Org1MSP/Writers 2017-11-24 11:05:27.870 UTC [common/configtx] addToMap -> DEBU 047 Adding to config map: [Policy] /Channel/Consortiums/SampleConsortium/Org1MSP/Admins 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 048 Adding to config map: [Values] /Channel/Consortiums/SampleConsortium/ChannelCreationPolicy 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 049 Adding to config map: [Policy] /Channel/Consortiums/Admins 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 04a Adding to config map: [Groups] /Channel/Orderer 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 04b Adding to config map: [Groups] /Channel/Orderer/Orgorderer1MSP 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 04c Adding to config map: [Values] /Channel/Orderer/Orgorderer1MSP/MSP 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 04d Adding to config map: [Policy] /Channel/Orderer/Orgorderer1MSP/Admins 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 04e Adding to config map: [Policy] /Channel/Orderer/Orgorderer1MSP/Readers 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 04f Adding to config map: [Policy] /Channel/Orderer/Orgorderer1MSP/Writers 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 050 Adding to config map: [Values] /Channel/Orderer/BatchSize 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 051 Adding to config map: [Values] /Channel/Orderer/BatchTimeout 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 052 Adding to config map: [Values] /Channel/Orderer/ChannelRestrictions 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 053 Adding to config map: [Values] /Channel/Orderer/KafkaBrokers 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 054 Adding to config map: [Values] /Channel/Orderer/ConsensusType 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 055 Adding to config map: [Policy] /Channel/Orderer/Admins 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 056 Adding to config map: [Policy] /Channel/Orderer/BlockValidation 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 057 Adding to config map: [Policy] /Channel/Orderer/Readers 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 058 Adding to config map: [Policy] /Channel/Orderer/Writers 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 059 Adding to config map: [Values] /Channel/BlockDataHashingStructure 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 05a Adding to config map: [Values] /Channel/OrdererAddresses 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 05b Adding to config map: [Values] /Channel/HashingAlgorithm 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 05c Adding to config map: [Policy] /Channel/Readers 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 05d Adding to config map: [Policy] /Channel/Writers 2017-11-24 11:05:27.871 UTC [common/configtx] addToMap -> DEBU 05e Adding to config map: [Policy] /Channel/Admins 2017-11-24 11:05:27.871 UTC [common/configtx] processConfig -> DEBU 05f Beginning new config for channel testchainid 2017-11-24 11:05:27.871 UTC [common/config] NewStandardValues -> DEBU 060 Initializing protos for *config.ChannelProtos 2017-11-24 11:05:27.871 UTC [common/config] initializeProtosStruct -> DEBU 061 Processing field: HashingAlgorithm 2017-11-24 11:05:27.871 UTC [common/config] initializeProtosStruct -> DEBU 062 Processing field: BlockDataHashingStructure 2017-11-24 11:05:27.871 UTC [common/config] initializeProtosStruct -> DEBU 063 Processing field: OrdererAddresses 2017-11-24 11:05:27.871 UTC [common/config] initializeProtosStruct -> DEBU 064 Processing field: Consortium 2017-11-24 11:05:27.871 UTC [policies] ProposePolicy -> DEBU 065 Proposed new policy Readers for Channel 2017-11-24 11:05:27.871 UTC [policies] ProposePolicy -> DEBU 066 Proposed new policy Writers for Channel 2017-11-24 11:05:27.871 UTC [policies] ProposePolicy -> DEBU 067 Proposed new policy Admins for Channel 2017-11-24 11:05:27.871 UTC [policies] ProposePolicy -> DEBU 068 Proposed new policy Admins for Consortiums 2017-11-24 11:05:27.871 UTC [common/config] NewStandardValues -> DEBU 069 Initializing protos for *config.ConsortiumProtos 2017-11-24 11:05:27.871 UTC [common/config] initializeProtosStruct -> DEBU 06a Processing field: ChannelCreationPolicy 2017-11-24 11:05:27.871 UTC [common/config] NewStandardValues -> DEBU 06b Initializing protos for *config.OrganizationProtos 2017-11-24 11:05:27.871 UTC [common/config] initializeProtosStruct -> DEBU 06c Processing field: MSP 2017-11-24 11:05:27.872 UTC [policies] ProposePolicy -> DEBU 06d Proposed new policy Writers for Org2MSP 2017-11-24 11:05:27.872 UTC [policies] ProposePolicy -> DEBU 06e Proposed new policy Admins for Org2MSP 2017-11-24 11:05:27.872 UTC [policies] ProposePolicy -> DEBU 06f Proposed new policy Readers for Org2MSP 2017-11-24 11:05:27.872 UTC [common/config] NewStandardValues -> DEBU 070 Initializing protos for *config.OrganizationProtos 2017-11-24 11:05:27.872 UTC [common/config] initializeProtosStruct -> DEBU 071 Processing field: MSP 2017-11-24 11:05:27.872 UTC [policies] ProposePolicy -> DEBU 072 Proposed new policy Writers for Org1MSP 2017-11-24 11:05:27.872 UTC [policies] ProposePolicy -> DEBU 073 Proposed new policy Admins for Org1MSP 2017-11-24 11:05:27.872 UTC [policies] ProposePolicy -> DEBU 074 Proposed new policy Readers for Org1MSP 2017-11-24 11:05:27.872 UTC [common/config] NewStandardValues -> DEBU 075 Initializing protos for *config.OrdererProtos 2017-11-24 11:05:27.872 UTC [common/config] initializeProtosStruct -> DEBU 076 Processing field: ConsensusType 2017-11-24 11:05:27.872 UTC [common/config] initializeProtosStruct -> DEBU 077 Processing field: BatchSize 2017-11-24 11:05:27.872 UTC [common/config] initializeProtosStruct -> DEBU 078 Processing field: BatchTimeout 2017-11-24 11:05:27.872 UTC [common/config] initializeProtosStruct -> DEBU 079 Processing field: KafkaBrokers 2017-11-24 11:05:27.872 UTC [common/config] initializeProtosStruct -> DEBU 07a Processing field: ChannelRestrictions 2017-11-24 11:05:27.872 UTC [policies] ProposePolicy -> DEBU 07b Proposed new policy Admins for Orderer 2017-11-24 11:05:27.872 UTC [policies] ProposePolicy -> DEBU 07c Proposed new policy BlockValidation for Orderer 2017-11-24 11:05:27.872 UTC [policies] ProposePolicy -> DEBU 07d Proposed new policy Readers for Orderer 2017-11-24 11:05:27.872 UTC [policies] ProposePolicy -> DEBU 07e Proposed new policy Writers for Orderer 2017-11-24 11:05:27.872 UTC [common/config] NewStandardValues -> DEBU 07f Initializing protos for *config.OrganizationProtos 2017-11-24 11:05:27.872 UTC [common/config] initializeProtosStruct -> DEBU 080 Processing field: MSP 2017-11-24 11:05:27.872 UTC [policies] ProposePolicy -> DEBU 081 Proposed new policy Readers for Orgorderer1MSP 2017-11-24 11:05:27.872 UTC [policies] ProposePolicy -> DEBU 082 Proposed new policy Writers for Orgorderer1MSP 2017-11-24 11:05:27.872 UTC [policies] ProposePolicy -> DEBU 083 Proposed new policy Admins for Orgorderer1MSP 2017-11-24 11:05:27.872 UTC [common/config] validateMSP -> DEBU 084 Setting up MSP for org Org2MSP 2017-11-24 11:05:27.872 UTC [msp] NewBccspMsp -> DEBU 085 Creating BCCSP-based MSP instance 2017-11-24 11:05:27.872 UTC [msp] Setup -> DEBU 086 Setting up MSP instance Org2MSP 2017-11-24 11:05:27.872 UTC [msp/identity] newIdentity -> DEBU 087 Creating identity instance for ID &{Org2MSP da2fafa0c7c0e56b1826c9f427c475f4f28a74f42152b1c70b7340125c302885} 2017-11-24 11:05:27.872 UTC [msp/identity] newIdentity -> DEBU 088 Creating identity instance for ID &{Org2MSP 09b6555908e39a6ebf1c956673f38f66c9082c424b9e64943d3a49ec2e455617} 2017-11-24 11:05:27.872 UTC [msp/identity] newIdentity -> DEBU 089 Creating identity instance for ID &{Org2MSP 09b6555908e39a6ebf1c956673f38f66c9082c424b9e64943d3a49ec2e455617} 2017-11-24 11:05:27.873 UTC [msp] Validate -> DEBU 08a MSP Org2MSP validating identity 2017-11-24 11:05:27.873 UTC [common/config] validateMSP -> DEBU 08b Setting up MSP for org Org1MSP 2017-11-24 11:05:27.873 UTC [msp] NewBccspMsp -> DEBU 08c Creating BCCSP-based MSP instance 2017-11-24 11:05:27.873 UTC [msp] Setup -> DEBU 08d Setting up MSP instance Org1MSP 2017-11-24 11:05:27.873 UTC [msp/identity] newIdentity -> DEBU 08e Creating identity instance for ID &{Org1MSP 9de37b4a016558ca2dc03d96145faf3f514231e91ad73d9db11aee5c6ae60744} 2017-11-24 11:05:27.873 UTC [msp/identity] newIdentity -> DEBU 08f Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:05:27.874 UTC [msp/identity] newIdentity -> DEBU 090 Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:05:27.874 UTC [msp] Validate -> DEBU 091 MSP Org1MSP validating identity 2017-11-24 11:05:27.874 UTC [common/config] validateMSP -> DEBU 092 Setting up MSP for org Orgorderer1MSP 2017-11-24 11:05:27.874 UTC [msp] NewBccspMsp -> DEBU 093 Creating BCCSP-based MSP instance 2017-11-24 11:05:27.874 UTC [msp] Setup -> DEBU 094 Setting up MSP instance Orgorderer1MSP 2017-11-24 11:05:27.874 UTC [msp/identity] newIdentity -> DEBU 095 Creating identity instance for ID &{Orgorderer1MSP f879c2ec0ac3215b0a2042a3073b43e0db0f66a60e2c094b1f9b1941273f0d0d} 2017-11-24 11:05:27.875 UTC [msp/identity] newIdentity -> DEBU 096 Creating identity instance for ID &{Orgorderer1MSP 8da4e1d96dad42b4e45a7323b55ddfc8af2280460c23fb4e66b45f4466435299} 2017-11-24 11:05:27.875 UTC [msp/identity] newIdentity -> DEBU 097 Creating identity instance for ID &{Orgorderer1MSP 8da4e1d96dad42b4e45a7323b55ddfc8af2280460c23fb4e66b45f4466435299} 2017-11-24 11:05:27.875 UTC [msp] Validate -> DEBU 098 MSP Orgorderer1MSP validating identity 2017-11-24 11:05:27.876 UTC [msp] Setup -> DEBU 099 Setting up the MSP manager (3 msps) 2017-11-24 11:05:27.876 UTC [msp] Setup -> DEBU 09a MSP manager setup complete, setup 3 msps 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 09b Returning policy Admins for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 09c In commit adding relative sub-policy Org2MSP/Admins to SampleConsortium 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 09d Returning policy Readers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 09e In commit adding relative sub-policy Org2MSP/Readers to SampleConsortium 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 09f Returning policy Writers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0a0 In commit adding relative sub-policy Org2MSP/Writers to SampleConsortium 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0a1 Returning policy Writers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0a2 In commit adding relative sub-policy Org1MSP/Writers to SampleConsortium 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0a3 Returning policy Admins for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0a4 In commit adding relative sub-policy Org1MSP/Admins to SampleConsortium 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0a5 Returning policy Readers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0a6 In commit adding relative sub-policy Org1MSP/Readers to SampleConsortium 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0a7 Returning policy Org2MSP/Admins for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0a8 In commit adding relative sub-policy SampleConsortium/Org2MSP/Admins to Consortiums 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0a9 Returning policy Org2MSP/Readers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0aa In commit adding relative sub-policy SampleConsortium/Org2MSP/Readers to Consortiums 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0ab Returning policy Org2MSP/Writers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0ac In commit adding relative sub-policy SampleConsortium/Org2MSP/Writers to Consortiums 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0ad Returning policy Org1MSP/Writers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0ae In commit adding relative sub-policy SampleConsortium/Org1MSP/Writers to Consortiums 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0af Returning policy Org1MSP/Admins for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0b0 In commit adding relative sub-policy SampleConsortium/Org1MSP/Admins to Consortiums 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0b1 Returning policy Org1MSP/Readers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0b2 In commit adding relative sub-policy SampleConsortium/Org1MSP/Readers to Consortiums 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0b3 Returning policy Admins for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0b4 In commit adding relative sub-policy Orgorderer1MSP/Admins to Orderer 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0b5 Returning policy Readers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0b6 In commit adding relative sub-policy Orgorderer1MSP/Readers to Orderer 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0b7 Returning policy Writers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0b8 In commit adding relative sub-policy Orgorderer1MSP/Writers to Orderer 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0b9 Returning policy Admins for evaluation 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0ba Returning policy Writers for evaluation 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0bb Returning policy Readers for evaluation 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0bc Returning policy Writers for evaluation 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0bd Returning policy SampleConsortium/Org2MSP/Writers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0be In commit adding relative sub-policy Consortiums/SampleConsortium/Org2MSP/Writers to Channel 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0bf Returning policy SampleConsortium/Org1MSP/Writers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0c0 In commit adding relative sub-policy Consortiums/SampleConsortium/Org1MSP/Writers to Channel 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0c1 Returning policy SampleConsortium/Org1MSP/Admins for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0c2 In commit adding relative sub-policy Consortiums/SampleConsortium/Org1MSP/Admins to Channel 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0c3 Returning policy SampleConsortium/Org1MSP/Readers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0c4 In commit adding relative sub-policy Consortiums/SampleConsortium/Org1MSP/Readers to Channel 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0c5 Returning policy Admins for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0c6 In commit adding relative sub-policy Consortiums/Admins to Channel 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0c7 Returning policy SampleConsortium/Org2MSP/Admins for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0c8 In commit adding relative sub-policy Consortiums/SampleConsortium/Org2MSP/Admins to Channel 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0c9 Returning policy SampleConsortium/Org2MSP/Readers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0ca In commit adding relative sub-policy Consortiums/SampleConsortium/Org2MSP/Readers to Channel 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0cb Returning policy BlockValidation for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0cc In commit adding relative sub-policy Orderer/BlockValidation to Channel 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0cd Returning policy Readers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0ce In commit adding relative sub-policy Orderer/Readers to Channel 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0cf Returning policy Writers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0d0 In commit adding relative sub-policy Orderer/Writers to Channel 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0d1 Returning policy Orgorderer1MSP/Admins for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0d2 In commit adding relative sub-policy Orderer/Orgorderer1MSP/Admins to Channel 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0d3 Returning policy Orgorderer1MSP/Readers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0d4 In commit adding relative sub-policy Orderer/Orgorderer1MSP/Readers to Channel 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0d5 Returning policy Orgorderer1MSP/Writers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0d6 In commit adding relative sub-policy Orderer/Orgorderer1MSP/Writers to Channel 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0d7 Returning policy Admins for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0d8 In commit adding relative sub-policy Orderer/Admins to Channel 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0d9 Returning policy Readers for evaluation 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0da Returning dummy reject all policy because Readers could not be found in /Consortiums/Readers 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0db Returning policy Writers for evaluation 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0dc Returning dummy reject all policy because Writers could not be found in /Consortiums/Writers 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0dd Returning policy Admins for evaluation 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0de Returning policy Admins for evaluation 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0df Returning policy Readers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0e0 As expected, current configuration has policy '/Channel/Readers' 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0e1 Returning policy Writers for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0e2 As expected, current configuration has policy '/Channel/Writers' 2017-11-24 11:05:27.876 UTC [policies] GetPolicy -> DEBU 0e3 Returning policy Orderer/BlockValidation for evaluation 2017-11-24 11:05:27.876 UTC [policies] CommitProposals -> DEBU 0e4 As expected, current configuration has policy '/Channel/Orderer/BlockValidation' 2017-11-24 11:05:27.876 UTC [fsblkstorage] retrieveBlockByNumber -> DEBU 0e5 retrieveBlockByNumber() - blockNum = [0] 2017-11-24 11:05:27.876 UTC [fsblkstorage] newBlockfileStream -> DEBU 0e6 newBlockfileStream(): filePath=[/var/hyperledger/production/orderer/chains/testchainid/blockfile_000000], startOffset=[0] 2017-11-24 11:05:27.876 UTC [fsblkstorage] nextBlockBytesAndPlacementInfo -> DEBU 0e7 Remaining bytes=[8884], Going to peek [8] bytes 2017-11-24 11:05:27.876 UTC [fsblkstorage] nextBlockBytesAndPlacementInfo -> DEBU 0e8 Returning blockbytes - length=[8882], placementInfo={fileNum=[0], startOffset=[0], bytesOffset=[2]} 2017-11-24 11:05:27.877 UTC [orderer/multichain] newChainSupport -> DEBU 0e9 [channel: testchainid] Retrieved metadata for tip of chain (blockNumber=0, lastConfig=0, lastConfigSeq=0): 2017-11-24 11:05:27.877 UTC [orderer/kafka] newChain -> INFO 0ea [channel: testchainid] Starting chain with last persisted offset -3 and last recorded block 0 2017-11-24 11:05:27.877 UTC [orderer/multichain] NewManagerImpl -> INFO 0eb Starting with system channel testchainid and orderer type kafka 2017-11-24 11:05:27.877 UTC [orderer/main] main -> INFO 0ec Beginning to serve requests 2017-11-24 11:05:27.877 UTC [orderer/kafka] setupProducerForChannel -> INFO 0ed [channel: testchainid] Setting up the producer for this channel... 2017-11-24 11:05:27.877 UTC [orderer/kafka] try -> DEBU 0ee [channel: testchainid] Retrying every 1s for a total of 30s 2017-11-24 11:05:28.877 UTC [orderer/kafka] try -> DEBU 0ef [channel: testchainid] Connecting to the Kafka cluster [sarama] 2017/11/24 11:05:28.877403 client.go:110: Initializing new client [sarama] 2017/11/24 11:05:28.877432 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:28.877484 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:28.877511 client.go:601: client/metadata fetching metadata for all topics from broker kafka1.kafka:9092 [sarama] 2017/11/24 11:05:28.879134 broker.go:96: Failed to connect to broker kafka1.kafka:9092: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:28.879164 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:28.879174 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:28.879198 client.go:601: client/metadata fetching metadata for all topics from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:28.880108 broker.go:96: Failed to connect to broker kafka3.kafka:9092: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:28.880149 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:28.880160 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:28.880184 client.go:601: client/metadata fetching metadata for all topics from broker kafka2.kafka:9092 [sarama] 2017/11/24 11:05:28.881105 broker.go:96: Failed to connect to broker kafka2.kafka:9092: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:28.881139 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:28.881150 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:28.881172 client.go:601: client/metadata fetching metadata for all topics from broker kafka0.kafka:9092 [sarama] 2017/11/24 11:05:28.883329 broker.go:96: Failed to connect to broker kafka0.kafka:9092: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:28.883352 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:28.883357 client.go:626: client/metadata no available broker to send metadata request to [sarama] 2017/11/24 11:05:28.883367 client.go:428: client/brokers resurrecting 4 dead seed brokers [sarama] 2017/11/24 11:05:28.883373 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:29.133491 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.133531 client.go:601: client/metadata fetching metadata for all topics from broker kafka1.kafka:9092 [sarama] 2017/11/24 11:05:29.134725 broker.go:96: Failed to connect to broker kafka1.kafka:9092: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.134749 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.134761 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.134776 client.go:601: client/metadata fetching metadata for all topics from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:29.135783 broker.go:96: Failed to connect to broker kafka3.kafka:9092: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.135806 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.135813 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.135827 client.go:601: client/metadata fetching metadata for all topics from broker kafka2.kafka:9092 [sarama] 2017/11/24 11:05:29.136782 broker.go:96: Failed to connect to broker kafka2.kafka:9092: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.136804 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.136809 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.136822 client.go:601: client/metadata fetching metadata for all topics from broker kafka0.kafka:9092 [sarama] 2017/11/24 11:05:29.137812 broker.go:96: Failed to connect to broker kafka0.kafka:9092: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.137834 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.137840 client.go:626: client/metadata no available broker to send metadata request to [sarama] 2017/11/24 11:05:29.137844 client.go:428: client/brokers resurrecting 4 dead seed brokers [sarama] 2017/11/24 11:05:29.137856 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:29.387974 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.388006 client.go:601: client/metadata fetching metadata for all topics from broker kafka1.kafka:9092 [sarama] 2017/11/24 11:05:29.390210 broker.go:96: Failed to connect to broker kafka1.kafka:9092: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.390233 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.390239 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.390260 client.go:601: client/metadata fetching metadata for all topics from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:29.391660 broker.go:96: Failed to connect to broker kafka3.kafka:9092: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.391681 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.391686 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.391700 client.go:601: client/metadata fetching metadata for all topics from broker kafka2.kafka:9092 [sarama] 2017/11/24 11:05:29.392973 broker.go:96: Failed to connect to broker kafka2.kafka:9092: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.392996 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.393007 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.393027 client.go:601: client/metadata fetching metadata for all topics from broker kafka0.kafka:9092 [sarama] 2017/11/24 11:05:29.393930 broker.go:96: Failed to connect to broker kafka0.kafka:9092: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.393952 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.393964 client.go:626: client/metadata no available broker to send metadata request to [sarama] 2017/11/24 11:05:29.393968 client.go:428: client/brokers resurrecting 4 dead seed brokers [sarama] 2017/11/24 11:05:29.393980 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:29.644104 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.644159 client.go:601: client/metadata fetching metadata for all topics from broker kafka1.kafka:9092 [sarama] 2017/11/24 11:05:29.645701 broker.go:96: Failed to connect to broker kafka1.kafka:9092: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.645725 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.645732 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.645742 client.go:601: client/metadata fetching metadata for all topics from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:29.646858 broker.go:96: Failed to connect to broker kafka3.kafka:9092: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.646875 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.646880 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.646894 client.go:601: client/metadata fetching metadata for all topics from broker kafka2.kafka:9092 [sarama] 2017/11/24 11:05:29.647815 broker.go:96: Failed to connect to broker kafka2.kafka:9092: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.647849 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.647859 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.647872 client.go:601: client/metadata fetching metadata for all topics from broker kafka0.kafka:9092 [sarama] 2017/11/24 11:05:29.648762 broker.go:96: Failed to connect to broker kafka0.kafka:9092: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.648783 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.648790 client.go:626: client/metadata no available broker to send metadata request to [sarama] 2017/11/24 11:05:29.648794 client.go:428: client/brokers resurrecting 4 dead seed brokers [sarama] 2017/11/24 11:05:29.648799 client.go:187: Closing Client 2017-11-24 11:05:29.877 UTC [orderer/kafka] try -> DEBU 0f0 [channel: testchainid] Connecting to the Kafka cluster [sarama] 2017/11/24 11:05:29.877424 client.go:110: Initializing new client [sarama] 2017/11/24 11:05:29.877439 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.877486 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.877511 client.go:601: client/metadata fetching metadata for all topics from broker kafka1.kafka:9092 [sarama] 2017/11/24 11:05:29.878795 broker.go:96: Failed to connect to broker kafka1.kafka:9092: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.878820 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.878838 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.878858 client.go:601: client/metadata fetching metadata for all topics from broker kafka0.kafka:9092 [sarama] 2017/11/24 11:05:29.879749 broker.go:96: Failed to connect to broker kafka0.kafka:9092: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.879772 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.879783 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.879802 client.go:601: client/metadata fetching metadata for all topics from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:29.880544 broker.go:96: Failed to connect to broker kafka3.kafka:9092: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.880558 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.880563 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:29.880579 client.go:601: client/metadata fetching metadata for all topics from broker kafka2.kafka:9092 [sarama] 2017/11/24 11:05:29.881451 broker.go:96: Failed to connect to broker kafka2.kafka:9092: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.881471 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:29.881476 client.go:626: client/metadata no available broker to send metadata request to [sarama] 2017/11/24 11:05:29.881486 client.go:428: client/brokers resurrecting 4 dead seed brokers [sarama] 2017/11/24 11:05:29.881492 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:30.131627 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:30.131667 client.go:601: client/metadata fetching metadata for all topics from broker kafka1.kafka:9092 [sarama] 2017/11/24 11:05:30.134011 broker.go:96: Failed to connect to broker kafka1.kafka:9092: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.134038 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.134044 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:30.134063 client.go:601: client/metadata fetching metadata for all topics from broker kafka0.kafka:9092 [sarama] 2017/11/24 11:05:30.135096 broker.go:96: Failed to connect to broker kafka0.kafka:9092: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.135125 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.135131 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:30.135151 client.go:601: client/metadata fetching metadata for all topics from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:30.135981 broker.go:96: Failed to connect to broker kafka3.kafka:9092: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.136004 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.136014 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:30.136027 client.go:601: client/metadata fetching metadata for all topics from broker kafka2.kafka:9092 [sarama] 2017/11/24 11:05:30.137153 broker.go:96: Failed to connect to broker kafka2.kafka:9092: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.137176 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.137180 client.go:626: client/metadata no available broker to send metadata request to [sarama] 2017/11/24 11:05:30.137190 client.go:428: client/brokers resurrecting 4 dead seed brokers [sarama] 2017/11/24 11:05:30.137197 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:30.387309 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:30.387351 client.go:601: client/metadata fetching metadata for all topics from broker kafka1.kafka:9092 [sarama] 2017/11/24 11:05:30.388613 broker.go:96: Failed to connect to broker kafka1.kafka:9092: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.388639 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.388652 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:30.388666 client.go:601: client/metadata fetching metadata for all topics from broker kafka0.kafka:9092 [sarama] 2017/11/24 11:05:30.389639 broker.go:96: Failed to connect to broker kafka0.kafka:9092: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.389654 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.389659 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:30.389671 client.go:601: client/metadata fetching metadata for all topics from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:30.390402 broker.go:96: Failed to connect to broker kafka3.kafka:9092: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.390421 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.390426 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:30.390439 client.go:601: client/metadata fetching metadata for all topics from broker kafka2.kafka:9092 [sarama] 2017/11/24 11:05:30.391288 broker.go:96: Failed to connect to broker kafka2.kafka:9092: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.391303 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.391308 client.go:626: client/metadata no available broker to send metadata request to [sarama] 2017/11/24 11:05:30.391312 client.go:428: client/brokers resurrecting 4 dead seed brokers [sarama] 2017/11/24 11:05:30.391320 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:30.641439 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:30.641482 client.go:601: client/metadata fetching metadata for all topics from broker kafka1.kafka:9092 [sarama] 2017/11/24 11:05:30.642630 broker.go:96: Failed to connect to broker kafka1.kafka:9092: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.642654 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.642667 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:30.642681 client.go:601: client/metadata fetching metadata for all topics from broker kafka0.kafka:9092 [sarama] 2017/11/24 11:05:30.643610 broker.go:96: Failed to connect to broker kafka0.kafka:9092: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.643639 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.643646 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:30.643663 client.go:601: client/metadata fetching metadata for all topics from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:30.644437 broker.go:96: Failed to connect to broker kafka3.kafka:9092: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.644459 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.644471 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:30.644489 client.go:601: client/metadata fetching metadata for all topics from broker kafka2.kafka:9092 [sarama] 2017/11/24 11:05:30.645356 broker.go:96: Failed to connect to broker kafka2.kafka:9092: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.645377 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.645383 client.go:626: client/metadata no available broker to send metadata request to [sarama] 2017/11/24 11:05:30.645388 client.go:428: client/brokers resurrecting 4 dead seed brokers [sarama] 2017/11/24 11:05:30.645393 client.go:187: Closing Client [sarama] 2017/11/24 11:05:30.877432 client.go:110: Initializing new client [sarama] 2017/11/24 11:05:30.877447 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. 2017-11-24 11:05:30.877 UTC [orderer/kafka] try -> DEBU 0f1 [channel: testchainid] Connecting to the Kafka cluster [sarama] 2017/11/24 11:05:30.879324 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:30.879352 client.go:601: client/metadata fetching metadata for all topics from broker kafka2.kafka:9092 [sarama] 2017/11/24 11:05:30.880459 broker.go:96: Failed to connect to broker kafka2.kafka:9092: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.880485 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.880498 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:30.880512 client.go:601: client/metadata fetching metadata for all topics from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:30.881304 broker.go:96: Failed to connect to broker kafka3.kafka:9092: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.881322 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.14.199:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.881328 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:30.881341 client.go:601: client/metadata fetching metadata for all topics from broker kafka1.kafka:9092 [sarama] 2017/11/24 11:05:30.882139 broker.go:96: Failed to connect to broker kafka1.kafka:9092: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.882161 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.8.52:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.882168 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:30.882183 client.go:601: client/metadata fetching metadata for all topics from broker kafka0.kafka:9092 [sarama] 2017/11/24 11:05:30.882969 broker.go:96: Failed to connect to broker kafka0.kafka:9092: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.882988 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.9.203:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:30.882993 client.go:626: client/metadata no available broker to send metadata request to [sarama] 2017/11/24 11:05:30.882999 client.go:428: client/brokers resurrecting 4 dead seed brokers [sarama] 2017/11/24 11:05:30.883006 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:31.133150 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:31.133192 client.go:601: client/metadata fetching metadata for all topics from broker kafka2.kafka:9092 [sarama] 2017/11/24 11:05:31.134294 broker.go:96: Failed to connect to broker kafka2.kafka:9092: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:31.134311 client.go:620: client/metadata got error from broker while fetching metadata: dial tcp 172.19.5.12:9092: getsockopt: connection refused [sarama] 2017/11/24 11:05:31.134317 config.go:329: ClientID is the default of 'sarama', you should consider setting it to something application-specific. [sarama] 2017/11/24 11:05:31.134332 client.go:601: client/metadata fetching metadata for all topics from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:31.135200 broker.go:146: Connected to broker at kafka3.kafka:9092 (unregistered) [sarama] 2017/11/24 11:05:31.138014 client.go:154: Successfully initialized new client 2017-11-24 11:05:31.138 UTC [orderer/kafka] try -> DEBU 0f2 [channel: testchainid] Error is nil, breaking the retry loop 2017-11-24 11:05:31.138 UTC [orderer/kafka] startThread -> INFO 0f3 [channel: testchainid] Producer set up successfully 2017-11-24 11:05:31.138 UTC [orderer/kafka] sendConnectMessage -> INFO 0f4 [channel: testchainid] About to post the CONNECT message... 2017-11-24 11:05:31.138 UTC [orderer/kafka] try -> DEBU 0f5 [channel: testchainid] Retrying every 1s for a total of 30s 2017-11-24 11:05:32.138 UTC [orderer/kafka] try -> DEBU 0f6 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:32.138464 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:32.156910 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:32.156931 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:32.407022 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:32.410420 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:32.410443 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:32.660578 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:32.664201 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:32.664217 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:32.914342 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:32.916674 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:33.138390 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 2017-11-24 11:05:33.138 UTC [orderer/kafka] try -> DEBU 0f7 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:33.140553 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:33.140572 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:33.390718 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:33.393427 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:33.393443 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:33.643573 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:33.645823 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:33.645840 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:33.895968 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:33.898061 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:34.138 UTC [orderer/kafka] try -> DEBU 0f8 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:34.138381 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:34.141240 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:34.141254 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:34.391400 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:34.393234 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:34.393252 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:34.643392 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:34.645211 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:34.645229 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:34.895347 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:34.897310 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:35.138 UTC [orderer/kafka] try -> DEBU 0f9 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:35.138403 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:35.140256 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:35.140270 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:35.390404 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:35.392153 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:35.392171 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:35.642311 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:35.644400 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:35.644419 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:35.894605 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:35.896474 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:36.138 UTC [orderer/kafka] try -> DEBU 0fa [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:36.138395 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:36.140235 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:36.140252 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:36.390374 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:36.392250 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:36.392269 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:36.642404 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:36.644406 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:36.644425 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:36.894541 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:36.896210 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:37.138 UTC [orderer/kafka] try -> DEBU 0fb [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:37.138384 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:37.140133 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:37.140150 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:37.390287 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:37.392019 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:37.392036 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:37.642176 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:37.644019 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:37.644037 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:37.894182 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:37.896036 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:38.138387 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 2017-11-24 11:05:38.138 UTC [orderer/kafka] try -> DEBU 0fc [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:38.140338 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:38.140358 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:38.390491 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:38.392345 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:38.392362 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:38.642491 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:38.644269 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:38.644283 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:38.894412 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:38.896683 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:39.138 UTC [orderer/kafka] try -> DEBU 0fd [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:39.138375 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:39.140241 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:39.140258 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:39.390388 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:39.392098 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:39.392126 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:39.642265 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:39.643956 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:39.643980 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:39.894137 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:39.896184 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:40.138 UTC [orderer/kafka] try -> DEBU 0fe [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:40.138368 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:40.140100 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:40.140127 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:40.390248 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:40.392096 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:40.392123 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:40.642266 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:40.644154 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:40.644175 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:40.894316 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:40.895948 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:41.138 UTC [orderer/kafka] try -> DEBU 0ff [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:41.138374 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:41.140222 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:41.140238 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:41.390378 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:41.392142 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:41.392158 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:41.642293 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:41.644129 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:41.644147 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:41.894292 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:41.895831 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:42.138372 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 2017-11-24 11:05:42.138 UTC [orderer/kafka] try -> DEBU 100 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:42.140291 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:42.140309 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:42.390428 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:42.392095 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:42.392121 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:42.642255 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:42.644076 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:42.644092 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:42.894240 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:42.895858 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:43.138 UTC [orderer/kafka] try -> DEBU 101 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:43.138377 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:43.139965 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:43.139980 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:43.390103 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:43.391602 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:43.391620 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:43.641750 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:43.643280 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:43.643299 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:43.893436 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:43.894787 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:44.138361 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 2017-11-24 11:05:44.138 UTC [orderer/kafka] try -> DEBU 102 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:44.139875 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:44.139894 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:44.390024 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:44.391587 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:44.391605 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:44.641738 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:44.643382 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:44.643401 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:44.893513 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:44.895013 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:45.138388 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 2017-11-24 11:05:45.138 UTC [orderer/kafka] try -> DEBU 103 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:45.140133 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:45.140151 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:45.390297 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:45.391871 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:45.391891 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:45.642011 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:45.643748 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:45.643764 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:45.893924 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:45.895873 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:46.138379 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 2017-11-24 11:05:46.138 UTC [orderer/kafka] try -> DEBU 104 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:46.140064 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:46.140083 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:46.390188 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:46.391747 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:46.391768 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:46.641898 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:46.645373 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:46.645389 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:46.895518 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:46.897059 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:47.138 UTC [orderer/kafka] try -> DEBU 105 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:47.138385 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:47.140020 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:47.140035 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:47.390163 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:47.391918 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:47.391938 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:47.642064 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:47.643688 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:47.643701 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:47.893837 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:47.895487 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:48.138 UTC [orderer/kafka] try -> DEBU 106 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:48.138394 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:48.139965 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:48.139983 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:48.390131 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:48.392398 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:48.392417 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:48.642537 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:48.644424 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:48.644444 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:48.894584 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:48.896089 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:49.138 UTC [orderer/kafka] try -> DEBU 107 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:49.138381 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:49.139988 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:49.140006 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:49.390134 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:49.391577 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:49.391594 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:49.641736 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:49.643360 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:49.643377 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:49.893524 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:49.895084 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:50.138 UTC [orderer/kafka] try -> DEBU 108 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:50.138378 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:50.140106 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:50.140136 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:50.390275 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:50.391943 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:50.391960 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:50.642099 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:50.643573 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:50.643593 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:50.893730 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:50.895060 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:51.138 UTC [orderer/kafka] try -> DEBU 109 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:51.138420 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:51.140074 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:51.140093 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:51.390235 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:51.391744 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:51.391762 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:51.641916 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:51.643323 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:51.643341 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:51.893502 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:51.895019 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:52.138 UTC [orderer/kafka] try -> DEBU 10a [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:52.138378 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:52.139824 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:52.139842 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:52.389989 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:52.391559 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:52.391578 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:52.641725 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:52.643258 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:52.643276 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:52.893434 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:52.894854 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:53.138384 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 2017-11-24 11:05:53.138 UTC [orderer/kafka] try -> DEBU 10b [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:53.140057 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:53.140077 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:53.390226 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:53.391573 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:53.391594 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:53.641743 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:53.643245 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:53.643271 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:53.893419 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:53.894754 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:54.138395 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 2017-11-24 11:05:54.138 UTC [orderer/kafka] try -> DEBU 10c [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:54.139830 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:54.139848 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:54.389972 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:54.391638 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:54.391655 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:54.641798 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:54.643332 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:54.643349 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:54.893481 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:54.894952 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:55.138 UTC [orderer/kafka] try -> DEBU 10d [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:55.138368 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:55.139806 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:55.139823 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:55.389963 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:55.391258 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:55.391288 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:55.641418 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:55.642674 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:55.642691 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:55.892841 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:55.894304 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:56.138 UTC [orderer/kafka] try -> DEBU 10e [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:56.138381 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:56.139602 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:56.139619 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:56.389765 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:56.391334 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:56.391353 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:56.641493 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:56.642889 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:56.642916 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:56.893060 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:56.894469 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:57.138379 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 2017-11-24 11:05:57.138 UTC [orderer/kafka] try -> DEBU 10f [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:57.139641 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:57.139655 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:57.389790 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:57.391253 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:57.391271 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:57.641407 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:57.642719 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:57.642737 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:57.892881 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:57.894238 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:58.138 UTC [orderer/kafka] try -> DEBU 110 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:58.138392 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:58.139646 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:58.139663 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:58.389736 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:58.391056 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:58.391075 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:58.641215 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:58.642740 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:58.642756 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:58.892886 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:58.894031 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:05:59.138 UTC [orderer/kafka] try -> DEBU 111 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:05:59.138360 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:59.139659 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:59.139677 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:05:59.389812 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:59.391223 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:59.391241 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:05:59.641350 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:59.642828 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:05:59.642842 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:05:59.892984 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:05:59.894079 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:06:00.138 UTC [orderer/kafka] try -> DEBU 112 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:06:00.138367 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:06:00.139678 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:06:00.139696 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:06:00.389813 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:06:00.391023 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:06:00.391041 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:06:00.641189 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:06:00.642519 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:06:00.642538 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:06:00.892673 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:06:00.893968 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:06:01.138 UTC [orderer/kafka] try -> DEBU 113 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:06:01.138372 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:06:01.139582 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:06:01.139599 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:06:01.389733 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:06:01.390899 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:06:01.390929 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:06:01.641064 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:06:01.642507 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:06:01.642526 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:06:01.892686 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:06:01.894039 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:06:01.894 UTC [orderer/kafka] retry -> DEBU 114 [channel: testchainid] Switching to the long retry interval 2017-11-24 11:06:01.894 UTC [orderer/kafka] try -> DEBU 115 [channel: testchainid] Retrying every 5m0s for a total of 12h0m0s 2017-11-24 11:11:01.894 UTC [orderer/kafka] try -> DEBU 116 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:11:01.894391 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:11:01.895589 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:11:01.895605 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:11:02.145746 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:11:02.147109 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:11:02.147133 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:11:02.397266 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:11:02.398435 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:11:02.398452 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:11:02.648593 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:11:02.649958 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:15:31.138343 client.go:601: client/metadata fetching metadata for all topics from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:16:01.894389 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 2017-11-24 11:16:01.894 UTC [orderer/kafka] try -> DEBU 117 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:16:01.895608 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:16:01.895626 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:16:02.145752 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:16:02.147017 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:16:02.147035 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:16:02.397188 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:16:02.398395 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:16:02.398412 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:16:02.648552 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:16:02.649780 client.go:610: client/metadata found some partitions to be leaderless 2017-11-24 11:17:47.901 UTC [orderer/main] Deliver -> DEBU 118 Starting new Deliver handler 2017-11-24 11:17:47.901 UTC [orderer/common/deliver] Handle -> DEBU 119 Starting new deliver loop 2017-11-24 11:17:47.901 UTC [orderer/common/deliver] Handle -> DEBU 11a Attempting to read seek info message 2017-11-24 11:17:47.913 UTC [orderer/main] Broadcast -> DEBU 11b Starting new Broadcast handler 2017-11-24 11:17:47.913 UTC [orderer/common/broadcast] Handle -> DEBU 11c Starting new broadcast loop 2017-11-24 11:17:47.913 UTC [orderer/common/broadcast] Handle -> DEBU 11d Preprocessing CONFIG_UPDATE 2017-11-24 11:17:47.913 UTC [orderer/configupdate] Process -> DEBU 11e Processing channel creation request for channel mychannel 2017-11-24 11:17:47.913 UTC [msp] GetLocalMSP -> DEBU 11f Returning existing local MSP 2017-11-24 11:17:47.913 UTC [msp] GetDefaultSigningIdentity -> DEBU 120 Obtaining default signing identity 2017-11-24 11:17:47.913 UTC [msp] GetLocalMSP -> DEBU 121 Returning existing local MSP 2017-11-24 11:17:47.913 UTC [msp] GetDefaultSigningIdentity -> DEBU 122 Obtaining default signing identity 2017-11-24 11:17:47.913 UTC [msp/identity] Sign -> DEBU 123 Sign: plaintext: 0ABA060A1508011A0608DBFFDFD00522...07577269746572731A0641646D696E73 2017-11-24 11:17:47.913 UTC [msp/identity] Sign -> DEBU 124 Sign: digest: EFC8675EEB1C39B2FF0D7D23EE53F8AAB8C4B6550ED97F6EA563B0F61D91B2E8 2017-11-24 11:17:47.914 UTC [common/config] NewStandardValues -> DEBU 125 Initializing protos for *config.ChannelProtos 2017-11-24 11:17:47.914 UTC [common/config] initializeProtosStruct -> DEBU 126 Processing field: HashingAlgorithm 2017-11-24 11:17:47.914 UTC [common/config] initializeProtosStruct -> DEBU 127 Processing field: BlockDataHashingStructure 2017-11-24 11:17:47.914 UTC [common/config] initializeProtosStruct -> DEBU 128 Processing field: OrdererAddresses 2017-11-24 11:17:47.914 UTC [common/config] initializeProtosStruct -> DEBU 129 Processing field: Consortium 2017-11-24 11:17:47.914 UTC [common/configtx] addToMap -> DEBU 12a Adding to config map: [Groups] /Channel 2017-11-24 11:17:47.914 UTC [common/configtx] addToMap -> DEBU 12b Adding to config map: [Groups] /Channel/Orderer 2017-11-24 11:17:47.914 UTC [common/configtx] addToMap -> DEBU 12c Adding to config map: [Groups] /Channel/Orderer/Orgorderer1MSP 2017-11-24 11:17:47.914 UTC [common/configtx] addToMap -> DEBU 12d Adding to config map: [Values] /Channel/Orderer/Orgorderer1MSP/MSP 2017-11-24 11:17:47.914 UTC [common/configtx] addToMap -> DEBU 12e Adding to config map: [Policy] /Channel/Orderer/Orgorderer1MSP/Writers 2017-11-24 11:17:47.914 UTC [common/configtx] addToMap -> DEBU 12f Adding to config map: [Policy] /Channel/Orderer/Orgorderer1MSP/Admins 2017-11-24 11:17:47.914 UTC [common/configtx] addToMap -> DEBU 130 Adding to config map: [Policy] /Channel/Orderer/Orgorderer1MSP/Readers 2017-11-24 11:17:47.914 UTC [common/configtx] addToMap -> DEBU 131 Adding to config map: [Values] /Channel/Orderer/BatchTimeout 2017-11-24 11:17:47.914 UTC [common/configtx] addToMap -> DEBU 132 Adding to config map: [Values] /Channel/Orderer/ChannelRestrictions 2017-11-24 11:17:47.914 UTC [common/configtx] addToMap -> DEBU 133 Adding to config map: [Values] /Channel/Orderer/KafkaBrokers 2017-11-24 11:17:47.914 UTC [common/configtx] addToMap -> DEBU 134 Adding to config map: [Values] /Channel/Orderer/ConsensusType 2017-11-24 11:17:47.914 UTC [common/configtx] addToMap -> DEBU 135 Adding to config map: [Values] /Channel/Orderer/BatchSize 2017-11-24 11:17:47.914 UTC [common/configtx] addToMap -> DEBU 136 Adding to config map: [Policy] /Channel/Orderer/BlockValidation 2017-11-24 11:17:47.914 UTC [common/configtx] addToMap -> DEBU 137 Adding to config map: [Policy] /Channel/Orderer/Readers 2017-11-24 11:17:47.914 UTC [common/configtx] addToMap -> DEBU 138 Adding to config map: [Policy] /Channel/Orderer/Writers 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 139 Adding to config map: [Policy] /Channel/Orderer/Admins 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 13a Adding to config map: [Groups] /Channel/Application 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 13b Adding to config map: [Groups] /Channel/Application/Org2MSP 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 13c Adding to config map: [Values] /Channel/Application/Org2MSP/MSP 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 13d Adding to config map: [Policy] /Channel/Application/Org2MSP/Writers 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 13e Adding to config map: [Policy] /Channel/Application/Org2MSP/Admins 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 13f Adding to config map: [Policy] /Channel/Application/Org2MSP/Readers 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 140 Adding to config map: [Groups] /Channel/Application/Org1MSP 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 141 Adding to config map: [Values] /Channel/Application/Org1MSP/MSP 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 142 Adding to config map: [Policy] /Channel/Application/Org1MSP/Writers 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 143 Adding to config map: [Policy] /Channel/Application/Org1MSP/Admins 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 144 Adding to config map: [Policy] /Channel/Application/Org1MSP/Readers 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 145 Adding to config map: [Policy] /Channel/Application/ChannelCreationPolicy 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 146 Adding to config map: [Values] /Channel/BlockDataHashingStructure 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 147 Adding to config map: [Values] /Channel/OrdererAddresses 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 148 Adding to config map: [Values] /Channel/HashingAlgorithm 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 149 Adding to config map: [Values] /Channel/Consortium 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 14a Adding to config map: [Policy] /Channel/Admins 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 14b Adding to config map: [Policy] /Channel/Readers 2017-11-24 11:17:47.915 UTC [common/configtx] addToMap -> DEBU 14c Adding to config map: [Policy] /Channel/Writers 2017-11-24 11:17:47.915 UTC [common/configtx] processConfig -> DEBU 14d Beginning new config for channel mychannel 2017-11-24 11:17:47.915 UTC [common/config] NewStandardValues -> DEBU 14e Initializing protos for *config.ChannelProtos 2017-11-24 11:17:47.915 UTC [common/config] initializeProtosStruct -> DEBU 14f Processing field: HashingAlgorithm 2017-11-24 11:17:47.915 UTC [common/config] initializeProtosStruct -> DEBU 150 Processing field: BlockDataHashingStructure 2017-11-24 11:17:47.915 UTC [common/config] initializeProtosStruct -> DEBU 151 Processing field: OrdererAddresses 2017-11-24 11:17:47.915 UTC [common/config] initializeProtosStruct -> DEBU 152 Processing field: Consortium 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 153 Proposed new policy Readers for Channel 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 154 Proposed new policy Writers for Channel 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 155 Proposed new policy Admins for Channel 2017-11-24 11:17:47.916 UTC [common/config] NewStandardValues -> DEBU 156 Initializing protos for *config.OrdererProtos 2017-11-24 11:17:47.916 UTC [common/config] initializeProtosStruct -> DEBU 157 Processing field: ConsensusType 2017-11-24 11:17:47.916 UTC [common/config] initializeProtosStruct -> DEBU 158 Processing field: BatchSize 2017-11-24 11:17:47.916 UTC [common/config] initializeProtosStruct -> DEBU 159 Processing field: BatchTimeout 2017-11-24 11:17:47.916 UTC [common/config] initializeProtosStruct -> DEBU 15a Processing field: KafkaBrokers 2017-11-24 11:17:47.916 UTC [common/config] initializeProtosStruct -> DEBU 15b Processing field: ChannelRestrictions 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 15c Proposed new policy Admins for Orderer 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 15d Proposed new policy BlockValidation for Orderer 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 15e Proposed new policy Readers for Orderer 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 15f Proposed new policy Writers for Orderer 2017-11-24 11:17:47.916 UTC [common/config] NewStandardValues -> DEBU 160 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.916 UTC [common/config] initializeProtosStruct -> DEBU 161 Processing field: MSP 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 162 Proposed new policy Readers for Orgorderer1MSP 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 163 Proposed new policy Writers for Orgorderer1MSP 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 164 Proposed new policy Admins for Orgorderer1MSP 2017-11-24 11:17:47.916 UTC [common/config] NewStandardValues -> DEBU 165 Initializing protos for *struct {} 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 166 Proposed new policy ChannelCreationPolicy for Application 2017-11-24 11:17:47.916 UTC [common/config] NewStandardValues -> DEBU 167 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.916 UTC [common/config] initializeProtosStruct -> DEBU 168 Processing field: MSP 2017-11-24 11:17:47.916 UTC [common/config] NewStandardValues -> DEBU 169 Initializing protos for *config.ApplicationOrgProtos 2017-11-24 11:17:47.916 UTC [common/config] initializeProtosStruct -> DEBU 16a Processing field: AnchorPeers 2017-11-24 11:17:47.916 UTC [common/config] NewStandardValues -> DEBU 16b Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.916 UTC [common/config] initializeProtosStruct -> DEBU 16c Processing field: MSP 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 16d Proposed new policy Writers for Org2MSP 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 16e Proposed new policy Admins for Org2MSP 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 16f Proposed new policy Readers for Org2MSP 2017-11-24 11:17:47.916 UTC [common/config] NewStandardValues -> DEBU 170 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.916 UTC [common/config] initializeProtosStruct -> DEBU 171 Processing field: MSP 2017-11-24 11:17:47.916 UTC [common/config] NewStandardValues -> DEBU 172 Initializing protos for *config.ApplicationOrgProtos 2017-11-24 11:17:47.916 UTC [common/config] initializeProtosStruct -> DEBU 173 Processing field: AnchorPeers 2017-11-24 11:17:47.916 UTC [common/config] NewStandardValues -> DEBU 174 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.916 UTC [common/config] initializeProtosStruct -> DEBU 175 Processing field: MSP 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 176 Proposed new policy Writers for Org1MSP 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 177 Proposed new policy Admins for Org1MSP 2017-11-24 11:17:47.916 UTC [policies] ProposePolicy -> DEBU 178 Proposed new policy Readers for Org1MSP 2017-11-24 11:17:47.916 UTC [common/config] validateMSP -> DEBU 179 Setting up MSP for org Orgorderer1MSP 2017-11-24 11:17:47.916 UTC [msp] NewBccspMsp -> DEBU 17a Creating BCCSP-based MSP instance 2017-11-24 11:17:47.916 UTC [msp] Setup -> DEBU 17b Setting up MSP instance Orgorderer1MSP 2017-11-24 11:17:47.916 UTC [msp/identity] newIdentity -> DEBU 17c Creating identity instance for ID &{Orgorderer1MSP f879c2ec0ac3215b0a2042a3073b43e0db0f66a60e2c094b1f9b1941273f0d0d} 2017-11-24 11:17:47.917 UTC [msp/identity] newIdentity -> DEBU 17d Creating identity instance for ID &{Orgorderer1MSP 8da4e1d96dad42b4e45a7323b55ddfc8af2280460c23fb4e66b45f4466435299} 2017-11-24 11:17:47.917 UTC [msp/identity] newIdentity -> DEBU 17e Creating identity instance for ID &{Orgorderer1MSP 8da4e1d96dad42b4e45a7323b55ddfc8af2280460c23fb4e66b45f4466435299} 2017-11-24 11:17:47.917 UTC [msp] Validate -> DEBU 17f MSP Orgorderer1MSP validating identity 2017-11-24 11:17:47.918 UTC [common/config] Validate -> DEBU 180 Anchor peers for org Org2MSP are 2017-11-24 11:17:47.918 UTC [common/config] validateMSP -> DEBU 181 Setting up MSP for org Org2MSP 2017-11-24 11:17:47.918 UTC [msp] NewBccspMsp -> DEBU 182 Creating BCCSP-based MSP instance 2017-11-24 11:17:47.918 UTC [msp] Setup -> DEBU 183 Setting up MSP instance Org2MSP 2017-11-24 11:17:47.918 UTC [msp/identity] newIdentity -> DEBU 184 Creating identity instance for ID &{Org2MSP da2fafa0c7c0e56b1826c9f427c475f4f28a74f42152b1c70b7340125c302885} 2017-11-24 11:17:47.918 UTC [msp/identity] newIdentity -> DEBU 185 Creating identity instance for ID &{Org2MSP 09b6555908e39a6ebf1c956673f38f66c9082c424b9e64943d3a49ec2e455617} 2017-11-24 11:17:47.918 UTC [msp/identity] newIdentity -> DEBU 186 Creating identity instance for ID &{Org2MSP 09b6555908e39a6ebf1c956673f38f66c9082c424b9e64943d3a49ec2e455617} 2017-11-24 11:17:47.919 UTC [msp] Validate -> DEBU 187 MSP Org2MSP validating identity 2017-11-24 11:17:47.919 UTC [common/config] Validate -> DEBU 188 Anchor peers for org Org1MSP are 2017-11-24 11:17:47.919 UTC [common/config] validateMSP -> DEBU 189 Setting up MSP for org Org1MSP 2017-11-24 11:17:47.919 UTC [msp] NewBccspMsp -> DEBU 18a Creating BCCSP-based MSP instance 2017-11-24 11:17:47.919 UTC [msp] Setup -> DEBU 18b Setting up MSP instance Org1MSP 2017-11-24 11:17:47.919 UTC [msp/identity] newIdentity -> DEBU 18c Creating identity instance for ID &{Org1MSP 9de37b4a016558ca2dc03d96145faf3f514231e91ad73d9db11aee5c6ae60744} 2017-11-24 11:17:47.919 UTC [msp/identity] newIdentity -> DEBU 18d Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:17:47.920 UTC [msp/identity] newIdentity -> DEBU 18e Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:17:47.920 UTC [msp] Validate -> DEBU 18f MSP Org1MSP validating identity 2017-11-24 11:17:47.920 UTC [msp] Setup -> DEBU 190 Setting up the MSP manager (3 msps) 2017-11-24 11:17:47.920 UTC [msp] Setup -> DEBU 191 MSP manager setup complete, setup 3 msps 2017-11-24 11:17:47.920 UTC [policies] GetPolicy -> DEBU 192 Returning policy Admins for evaluation 2017-11-24 11:17:47.920 UTC [policies] CommitProposals -> DEBU 193 In commit adding relative sub-policy Orgorderer1MSP/Admins to Orderer 2017-11-24 11:17:47.920 UTC [policies] GetPolicy -> DEBU 194 Returning policy Readers for evaluation 2017-11-24 11:17:47.920 UTC [policies] CommitProposals -> DEBU 195 In commit adding relative sub-policy Orgorderer1MSP/Readers to Orderer 2017-11-24 11:17:47.920 UTC [policies] GetPolicy -> DEBU 196 Returning policy Writers for evaluation 2017-11-24 11:17:47.920 UTC [policies] CommitProposals -> DEBU 197 In commit adding relative sub-policy Orgorderer1MSP/Writers to Orderer 2017-11-24 11:17:47.920 UTC [policies] GetPolicy -> DEBU 198 Returning policy Admins for evaluation 2017-11-24 11:17:47.920 UTC [policies] GetPolicy -> DEBU 199 Returning policy Writers for evaluation 2017-11-24 11:17:47.920 UTC [policies] GetPolicy -> DEBU 19a Returning policy Readers for evaluation 2017-11-24 11:17:47.920 UTC [policies] GetPolicy -> DEBU 19b Returning policy Writers for evaluation 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 19c Returning policy Admins for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 19d In commit adding relative sub-policy Org2MSP/Admins to Application 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 19e Returning policy Readers for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 19f In commit adding relative sub-policy Org2MSP/Readers to Application 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1a0 Returning policy Writers for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1a1 In commit adding relative sub-policy Org2MSP/Writers to Application 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1a2 Returning policy Admins for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1a3 In commit adding relative sub-policy Org1MSP/Admins to Application 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1a4 Returning policy Readers for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1a5 In commit adding relative sub-policy Org1MSP/Readers to Application 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1a6 Returning policy Writers for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1a7 In commit adding relative sub-policy Org1MSP/Writers to Application 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1a8 Returning policy Admins for evaluation 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1a9 Returning policy Admins for evaluation 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1aa Returning policy Orgorderer1MSP/Admins for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1ab In commit adding relative sub-policy Orderer/Orgorderer1MSP/Admins to Channel 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1ac Returning policy Orgorderer1MSP/Readers for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1ad In commit adding relative sub-policy Orderer/Orgorderer1MSP/Readers to Channel 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1ae Returning policy Orgorderer1MSP/Writers for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1af In commit adding relative sub-policy Orderer/Orgorderer1MSP/Writers to Channel 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1b0 Returning policy Admins for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1b1 In commit adding relative sub-policy Orderer/Admins to Channel 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1b2 Returning policy BlockValidation for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1b3 In commit adding relative sub-policy Orderer/BlockValidation to Channel 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1b4 Returning policy Readers for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1b5 In commit adding relative sub-policy Orderer/Readers to Channel 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1b6 Returning policy Writers for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1b7 In commit adding relative sub-policy Orderer/Writers to Channel 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1b8 Returning policy Org2MSP/Writers for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1b9 In commit adding relative sub-policy Application/Org2MSP/Writers to Channel 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1ba Returning policy Org1MSP/Admins for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1bb In commit adding relative sub-policy Application/Org1MSP/Admins to Channel 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1bc Returning policy Org1MSP/Readers for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1bd In commit adding relative sub-policy Application/Org1MSP/Readers to Channel 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1be Returning policy Org1MSP/Writers for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1bf In commit adding relative sub-policy Application/Org1MSP/Writers to Channel 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1c0 Returning policy ChannelCreationPolicy for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1c1 In commit adding relative sub-policy Application/ChannelCreationPolicy to Channel 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1c2 Returning policy Org2MSP/Admins for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1c3 In commit adding relative sub-policy Application/Org2MSP/Admins to Channel 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1c4 Returning policy Org2MSP/Readers for evaluation 2017-11-24 11:17:47.921 UTC [policies] CommitProposals -> DEBU 1c5 In commit adding relative sub-policy Application/Org2MSP/Readers to Channel 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1c6 Returning policy Readers for evaluation 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1c7 Returning dummy reject all policy because Readers could not be found in /Application/Readers 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1c8 Returning dummy reject all policy because Writers could not be found in /Application/Writers 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1c9 Returning policy Writers for evaluation 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1ca Returning policy Admins for evaluation 2017-11-24 11:17:47.921 UTC [policies] GetPolicy -> DEBU 1cb Returning dummy reject all policy because Admins could not be found in /Application/Admins 2017-11-24 11:17:47.921 UTC [common/configtx] addToMap -> DEBU 1cc Adding to config map: [Groups] /Channel 2017-11-24 11:17:47.921 UTC [common/configtx] addToMap -> DEBU 1cd Adding to config map: [Groups] /Channel/Application 2017-11-24 11:17:47.921 UTC [common/configtx] addToMap -> DEBU 1ce Adding to config map: [Groups] /Channel/Application/Org2MSP 2017-11-24 11:17:47.921 UTC [common/configtx] addToMap -> DEBU 1cf Adding to config map: [Groups] /Channel/Application/Org1MSP 2017-11-24 11:17:47.921 UTC [common/configtx] addToMap -> DEBU 1d0 Adding to config map: [Values] /Channel/Consortium 2017-11-24 11:17:47.921 UTC [common/configtx] addToMap -> DEBU 1d1 Adding to config map: [Groups] /Channel 2017-11-24 11:17:47.921 UTC [common/configtx] addToMap -> DEBU 1d2 Adding to config map: [Groups] /Channel/Application 2017-11-24 11:17:47.921 UTC [common/configtx] addToMap -> DEBU 1d3 Adding to config map: [Groups] /Channel/Application/Org2MSP 2017-11-24 11:17:47.921 UTC [common/configtx] addToMap -> DEBU 1d4 Adding to config map: [Groups] /Channel/Application/Org1MSP 2017-11-24 11:17:47.922 UTC [common/configtx] addToMap -> DEBU 1d5 Adding to config map: [Policy] /Channel/Application/Admins 2017-11-24 11:17:47.922 UTC [common/configtx] addToMap -> DEBU 1d6 Adding to config map: [Policy] /Channel/Application/Writers 2017-11-24 11:17:47.922 UTC [common/configtx] addToMap -> DEBU 1d7 Adding to config map: [Policy] /Channel/Application/Readers 2017-11-24 11:17:47.922 UTC [common/configtx] addToMap -> DEBU 1d8 Adding to config map: [Values] /Channel/Consortium 2017-11-24 11:17:47.922 UTC [policies] GetPolicy -> DEBU 1d9 Returning policy ChannelCreationPolicy for evaluation 2017-11-24 11:17:47.922 UTC [cauthdsl] func1 -> DEBU 1da 0xc42012d030 gate 1511522267922130670 evaluation starts 2017-11-24 11:17:47.922 UTC [cauthdsl] func2 -> DEBU 1db 0xc42012d030 signed by 0 principal evaluation starts (used [false]) 2017-11-24 11:17:47.922 UTC [cauthdsl] func2 -> DEBU 1dc 0xc42012d030 processing identity 0 with bytes of 0a074f7267314d535012cf052d2d2d2d2d424547494e202d2d2d2d2d0a4d49494239544343415a756741774942416749514e664c46555972685a5a72476279495969417258697a414b42676771686b6a4f50515144416a42624d5173770a435159445651514745774a56557a45544d4245474131554543424d4b5132467361575a76636d3570595445574d4251474131554542784d4e5532467549455a790a5957356a61584e6a627a454e4d4173474131554543684d4562334a6e4d5445514d4134474131554541784d485932457562334a6e4d544165467730784e7a45780a4d6a51784d54417a4d7a5a61467730794e7a45784d6a49784d54417a4d7a5a614d453878437a414a42674e5642415954416c56544d524d7745515944565151490a45777044595778705a6d3979626d6c684d52597746415944565151484577315459573467526e4a68626d4e7063324e764d524d774551594456515144444170420a5a473170626b4276636d63784d466b77457759484b6f5a497a6a3043415159494b6f5a497a6a304441516344516741456154566341644f66596437516c6146420a6b38596c414b386c696548754f486f76746a38676e456638414e7663646b443149656d776f495961647a55666c496663433054513968332f6b6a2f2b746c436a0a477a6b756c614e4e4d45737744675944565230504151482f42415144416765414d41774741315564457745422f7751434d4141774b7759445652306a424351770a496f416745316a666f7041702f6f544e4c777138306f52533679524d30326d4b533433362b614a523070365948584177436759494b6f5a497a6a3045417749440a5341417752514968414c686a53624b54456238627450366a2f4332514f496e424a42594b51347066304f615670566c477073746c41694234364c516f414551320a74646d5350326b75597755506474417641784e2f6f3963366e57505363726d654d673d3d0a2d2d2d2d2d454e44202d2d2d2d2d0a 2017-11-24 11:17:47.922 UTC [msp/identity] newIdentity -> DEBU 1dd Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:17:47.922 UTC [cauthdsl] func2 -> DEBU 1de 0xc42012d030 identity 0 does not satisfy principal: The identity is a member of a different MSP (expected Org2MSP, got Org1MSP) 2017-11-24 11:17:47.922 UTC [cauthdsl] func2 -> DEBU 1df 0xc42012d030 principal evaluation fails 2017-11-24 11:17:47.922 UTC [cauthdsl] func1 -> DEBU 1e0 0xc42012d030 gate 1511522267922130670 evaluation fails 2017-11-24 11:17:47.922 UTC [cauthdsl] func1 -> DEBU 1e1 0xc42012d030 gate 1511522267922500032 evaluation starts 2017-11-24 11:17:47.922 UTC [cauthdsl] func2 -> DEBU 1e2 0xc42012d030 signed by 0 principal evaluation starts (used [false]) 2017-11-24 11:17:47.922 UTC [cauthdsl] func2 -> DEBU 1e3 0xc42012d030 processing identity 0 with bytes of 0a074f7267314d535012cf052d2d2d2d2d424547494e202d2d2d2d2d0a4d49494239544343415a756741774942416749514e664c46555972685a5a72476279495969417258697a414b42676771686b6a4f50515144416a42624d5173770a435159445651514745774a56557a45544d4245474131554543424d4b5132467361575a76636d3570595445574d4251474131554542784d4e5532467549455a790a5957356a61584e6a627a454e4d4173474131554543684d4562334a6e4d5445514d4134474131554541784d485932457562334a6e4d544165467730784e7a45780a4d6a51784d54417a4d7a5a61467730794e7a45784d6a49784d54417a4d7a5a614d453878437a414a42674e5642415954416c56544d524d7745515944565151490a45777044595778705a6d3979626d6c684d52597746415944565151484577315459573467526e4a68626d4e7063324e764d524d774551594456515144444170420a5a473170626b4276636d63784d466b77457759484b6f5a497a6a3043415159494b6f5a497a6a304441516344516741456154566341644f66596437516c6146420a6b38596c414b386c696548754f486f76746a38676e456638414e7663646b443149656d776f495961647a55666c496663433054513968332f6b6a2f2b746c436a0a477a6b756c614e4e4d45737744675944565230504151482f42415144416765414d41774741315564457745422f7751434d4141774b7759445652306a424351770a496f416745316a666f7041702f6f544e4c777138306f52533679524d30326d4b533433362b614a523070365948584177436759494b6f5a497a6a3045417749440a5341417752514968414c686a53624b54456238627450366a2f4332514f496e424a42594b51347066304f615670566c477073746c41694234364c516f414551320a74646d5350326b75597755506474417641784e2f6f3963366e57505363726d654d673d3d0a2d2d2d2d2d454e44202d2d2d2d2d0a 2017-11-24 11:17:47.922 UTC [msp/identity] newIdentity -> DEBU 1e4 Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:17:47.922 UTC [msp] SatisfiesPrincipal -> DEBU 1e5 Checking if identity satisfies ADMIN role for Org1MSP 2017-11-24 11:17:47.922 UTC [cauthdsl] func2 -> DEBU 1e6 0xc42012d030 principal matched by identity 0 2017-11-24 11:17:47.922 UTC [msp/identity] Verify -> DEBU 1e7 Verify: digest = 00000000 26 3f 5b 3c b8 01 7e b5 42 04 99 75 ee 4a ce 7c |&?[<..~.B..u.J.|| 00000010 ea 86 e1 c1 bc 5f 2e 87 89 18 8f 80 f2 c8 30 bc |....._........0.| 2017-11-24 11:17:47.922 UTC [msp/identity] Verify -> DEBU 1e8 Verify: sig = 00000000 30 45 02 21 00 82 80 1c 9b 9c 80 2e 86 09 ff 23 |0E.!...........#| 00000010 e3 11 92 d1 fa 58 d1 de ef 7b d7 2d 2d f9 88 fa |.....X...{.--...| 00000020 22 fb eb 8d 9c 02 20 71 ad 15 13 65 5e e1 eb 3c |"..... q...e^..<| 00000030 40 73 b9 31 f7 59 a8 5e 65 6d f3 c6 ff cd 00 b2 |@s.1.Y.^em......| 00000040 bd 9c 70 c5 f0 96 0e |..p....| 2017-11-24 11:17:47.922 UTC [cauthdsl] func2 -> DEBU 1e9 0xc42012d030 principal evaluation succeeds for identity 0 2017-11-24 11:17:47.922 UTC [cauthdsl] func1 -> DEBU 1ea 0xc42012d030 gate 1511522267922500032 evaluation succeeds 2017-11-24 11:17:47.923 UTC [common/configtx] processConfig -> DEBU 1eb Beginning new config for channel mychannel 2017-11-24 11:17:47.923 UTC [common/config] NewStandardValues -> DEBU 1ec Initializing protos for *config.ChannelProtos 2017-11-24 11:17:47.923 UTC [common/config] initializeProtosStruct -> DEBU 1ed Processing field: HashingAlgorithm 2017-11-24 11:17:47.923 UTC [common/config] initializeProtosStruct -> DEBU 1ee Processing field: BlockDataHashingStructure 2017-11-24 11:17:47.923 UTC [common/config] initializeProtosStruct -> DEBU 1ef Processing field: OrdererAddresses 2017-11-24 11:17:47.923 UTC [common/config] initializeProtosStruct -> DEBU 1f0 Processing field: Consortium 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 1f1 Proposed new policy Admins for Channel 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 1f2 Proposed new policy Readers for Channel 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 1f3 Proposed new policy Writers for Channel 2017-11-24 11:17:47.923 UTC [common/config] NewStandardValues -> DEBU 1f4 Initializing protos for *config.OrdererProtos 2017-11-24 11:17:47.923 UTC [common/config] initializeProtosStruct -> DEBU 1f5 Processing field: ConsensusType 2017-11-24 11:17:47.923 UTC [common/config] initializeProtosStruct -> DEBU 1f6 Processing field: BatchSize 2017-11-24 11:17:47.923 UTC [common/config] initializeProtosStruct -> DEBU 1f7 Processing field: BatchTimeout 2017-11-24 11:17:47.923 UTC [common/config] initializeProtosStruct -> DEBU 1f8 Processing field: KafkaBrokers 2017-11-24 11:17:47.923 UTC [common/config] initializeProtosStruct -> DEBU 1f9 Processing field: ChannelRestrictions 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 1fa Proposed new policy Writers for Orderer 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 1fb Proposed new policy Admins for Orderer 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 1fc Proposed new policy BlockValidation for Orderer 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 1fd Proposed new policy Readers for Orderer 2017-11-24 11:17:47.923 UTC [common/config] NewStandardValues -> DEBU 1fe Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.923 UTC [common/config] initializeProtosStruct -> DEBU 1ff Processing field: MSP 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 200 Proposed new policy Writers for Orgorderer1MSP 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 201 Proposed new policy Admins for Orgorderer1MSP 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 202 Proposed new policy Readers for Orgorderer1MSP 2017-11-24 11:17:47.923 UTC [common/config] NewStandardValues -> DEBU 203 Initializing protos for *struct {} 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 204 Proposed new policy Admins for Application 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 205 Proposed new policy Writers for Application 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 206 Proposed new policy Readers for Application 2017-11-24 11:17:47.923 UTC [common/config] NewStandardValues -> DEBU 207 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.923 UTC [common/config] initializeProtosStruct -> DEBU 208 Processing field: MSP 2017-11-24 11:17:47.923 UTC [common/config] NewStandardValues -> DEBU 209 Initializing protos for *config.ApplicationOrgProtos 2017-11-24 11:17:47.923 UTC [common/config] initializeProtosStruct -> DEBU 20a Processing field: AnchorPeers 2017-11-24 11:17:47.923 UTC [common/config] NewStandardValues -> DEBU 20b Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.923 UTC [common/config] initializeProtosStruct -> DEBU 20c Processing field: MSP 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 20d Proposed new policy Writers for Org1MSP 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 20e Proposed new policy Admins for Org1MSP 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 20f Proposed new policy Readers for Org1MSP 2017-11-24 11:17:47.923 UTC [common/config] NewStandardValues -> DEBU 210 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.923 UTC [common/config] initializeProtosStruct -> DEBU 211 Processing field: MSP 2017-11-24 11:17:47.923 UTC [common/config] NewStandardValues -> DEBU 212 Initializing protos for *config.ApplicationOrgProtos 2017-11-24 11:17:47.923 UTC [common/config] initializeProtosStruct -> DEBU 213 Processing field: AnchorPeers 2017-11-24 11:17:47.923 UTC [common/config] NewStandardValues -> DEBU 214 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.923 UTC [common/config] initializeProtosStruct -> DEBU 215 Processing field: MSP 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 216 Proposed new policy Writers for Org2MSP 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 217 Proposed new policy Admins for Org2MSP 2017-11-24 11:17:47.923 UTC [policies] ProposePolicy -> DEBU 218 Proposed new policy Readers for Org2MSP 2017-11-24 11:17:47.923 UTC [common/config] validateMSP -> DEBU 219 Setting up MSP for org Orgorderer1MSP 2017-11-24 11:17:47.923 UTC [msp] NewBccspMsp -> DEBU 21a Creating BCCSP-based MSP instance 2017-11-24 11:17:47.923 UTC [msp] Setup -> DEBU 21b Setting up MSP instance Orgorderer1MSP 2017-11-24 11:17:47.923 UTC [msp/identity] newIdentity -> DEBU 21c Creating identity instance for ID &{Orgorderer1MSP f879c2ec0ac3215b0a2042a3073b43e0db0f66a60e2c094b1f9b1941273f0d0d} 2017-11-24 11:17:47.924 UTC [msp/identity] newIdentity -> DEBU 21d Creating identity instance for ID &{Orgorderer1MSP 8da4e1d96dad42b4e45a7323b55ddfc8af2280460c23fb4e66b45f4466435299} 2017-11-24 11:17:47.924 UTC [msp/identity] newIdentity -> DEBU 21e Creating identity instance for ID &{Orgorderer1MSP 8da4e1d96dad42b4e45a7323b55ddfc8af2280460c23fb4e66b45f4466435299} 2017-11-24 11:17:47.924 UTC [msp] Validate -> DEBU 21f MSP Orgorderer1MSP validating identity 2017-11-24 11:17:47.925 UTC [common/config] Validate -> DEBU 220 Anchor peers for org Org1MSP are 2017-11-24 11:17:47.925 UTC [common/config] validateMSP -> DEBU 221 Setting up MSP for org Org1MSP 2017-11-24 11:17:47.925 UTC [msp] NewBccspMsp -> DEBU 222 Creating BCCSP-based MSP instance 2017-11-24 11:17:47.925 UTC [msp] Setup -> DEBU 223 Setting up MSP instance Org1MSP 2017-11-24 11:17:47.925 UTC [msp/identity] newIdentity -> DEBU 224 Creating identity instance for ID &{Org1MSP 9de37b4a016558ca2dc03d96145faf3f514231e91ad73d9db11aee5c6ae60744} 2017-11-24 11:17:47.925 UTC [msp/identity] newIdentity -> DEBU 225 Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:17:47.925 UTC [msp/identity] newIdentity -> DEBU 226 Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:17:47.926 UTC [msp] Validate -> DEBU 227 MSP Org1MSP validating identity 2017-11-24 11:17:47.926 UTC [common/config] Validate -> DEBU 228 Anchor peers for org Org2MSP are 2017-11-24 11:17:47.926 UTC [common/config] validateMSP -> DEBU 229 Setting up MSP for org Org2MSP 2017-11-24 11:17:47.926 UTC [msp] NewBccspMsp -> DEBU 22a Creating BCCSP-based MSP instance 2017-11-24 11:17:47.926 UTC [msp] Setup -> DEBU 22b Setting up MSP instance Org2MSP 2017-11-24 11:17:47.926 UTC [msp/identity] newIdentity -> DEBU 22c Creating identity instance for ID &{Org2MSP da2fafa0c7c0e56b1826c9f427c475f4f28a74f42152b1c70b7340125c302885} 2017-11-24 11:17:47.926 UTC [msp/identity] newIdentity -> DEBU 22d Creating identity instance for ID &{Org2MSP 09b6555908e39a6ebf1c956673f38f66c9082c424b9e64943d3a49ec2e455617} 2017-11-24 11:17:47.927 UTC [msp/identity] newIdentity -> DEBU 22e Creating identity instance for ID &{Org2MSP 09b6555908e39a6ebf1c956673f38f66c9082c424b9e64943d3a49ec2e455617} 2017-11-24 11:17:47.927 UTC [msp] Validate -> DEBU 22f MSP Org2MSP validating identity 2017-11-24 11:17:47.927 UTC [msp] Setup -> DEBU 230 Setting up the MSP manager (3 msps) 2017-11-24 11:17:47.927 UTC [msp] Setup -> DEBU 231 MSP manager setup complete, setup 3 msps 2017-11-24 11:17:47.927 UTC [msp] GetLocalMSP -> DEBU 232 Returning existing local MSP 2017-11-24 11:17:47.927 UTC [msp] GetDefaultSigningIdentity -> DEBU 233 Obtaining default signing identity 2017-11-24 11:17:47.927 UTC [msp] GetLocalMSP -> DEBU 234 Returning existing local MSP 2017-11-24 11:17:47.927 UTC [msp] GetDefaultSigningIdentity -> DEBU 235 Obtaining default signing identity 2017-11-24 11:17:47.928 UTC [msp/identity] Sign -> DEBU 236 Sign: plaintext: 0ABA060A1508011A0608DBFFDFD00522...D77CF4753ED31D6D083F85D2F0D36851 2017-11-24 11:17:47.928 UTC [msp/identity] Sign -> DEBU 237 Sign: digest: 8502A6E7134841BB8555234C486E8594DDDB6E89170BE8B96D4FFFDA53210D38 2017-11-24 11:17:47.928 UTC [msp] GetLocalMSP -> DEBU 238 Returning existing local MSP 2017-11-24 11:17:47.928 UTC [msp] GetDefaultSigningIdentity -> DEBU 239 Obtaining default signing identity 2017-11-24 11:17:47.928 UTC [msp] GetLocalMSP -> DEBU 23a Returning existing local MSP 2017-11-24 11:17:47.928 UTC [msp] GetDefaultSigningIdentity -> DEBU 23b Obtaining default signing identity 2017-11-24 11:17:47.928 UTC [msp/identity] Sign -> DEBU 23c Sign: plaintext: 0ABC060A1708041A0608DBFFDFD00522...C4E2174B017EB3B1F5E4D4D7F17D4A9E 2017-11-24 11:17:47.928 UTC [msp/identity] Sign -> DEBU 23d Sign: digest: 83F0DBE0BACE3FF2C946058C01673C51A63F839041B82AD628B3C713A57584A4 2017-11-24 11:17:47.928 UTC [orderer/common/broadcast] Handle -> DEBU 23e [channel: testchainid] Broadcast is filtering message of type ORDERER_TRANSACTION 2017-11-24 11:17:47.928 UTC [policies] GetPolicy -> DEBU 23f Returning policy Writers for evaluation 2017-11-24 11:17:47.928 UTC [cauthdsl] func1 -> DEBU 240 0xc42012d420 gate 1511522267928412510 evaluation starts 2017-11-24 11:17:47.928 UTC [cauthdsl] func2 -> DEBU 241 0xc42012d420 signed by 0 principal evaluation starts (used [false]) 2017-11-24 11:17:47.928 UTC [cauthdsl] func2 -> DEBU 242 0xc42012d420 processing identity 0 with bytes of 0a0e4f72676f726465726572314d535012f0052d2d2d2d2d424547494e202d2d2d2d2d0a4d494943446a4343416253674177494241674952414a666e7a4e31362b7756494f57507273347867576b6b77436759494b6f5a497a6a3045417749776154454c0a4d416b474131554542684d4356564d78457a415242674e5642416754436b4e6862476c6d62334a7561574578466a415542674e564241635444564e68626942470a636d467559326c7a593238784644415342674e5642416f54433239795a3239795a4756795a5849784d52637746515944565151444577356a59533576636d64760a636d526c636d56794d544165467730784e7a45784d6a51784d54417a4d7a5a61467730794e7a45784d6a49784d54417a4d7a5a614d466b78437a414a42674e560a42415954416c56544d524d77455159445651514945777044595778705a6d3979626d6c684d52597746415944565151484577315459573467526e4a68626d4e700a63324e764d523077477759445651514445785276636d526c636d56794d693576636d6476636d526c636d56794d54425a4d424d4742797147534d3439416745470a43437147534d34394177454841304941424c6559616f367142325a6a4536644c354b39584a775176747559374c616b483346477534576f784862496d637053760a4b4f4e465a465665317177486d37484161526d382b557a4c58684d7a684359654b76597759516d6a5454424c4d41344741315564447745422f775145417749480a6744414d42674e5648524d4241663845416a41414d437347413155644977516b4d434b41494a69483175533477575863526671327a49547049376951567533740a574b2b4866446e4a754264354f7773654d416f4743437147534d343942414d43413067414d4555434951434432334857774b43383949692f347a444e64666f4e0a4d7172746e4e4773614853524c465a4f446b564a39774967564f447a6255686d4e4f7a75757750795a6830483249523632586b41367869314b49726542496d700a3550673d0a2d2d2d2d2d454e44202d2d2d2d2d0a 2017-11-24 11:17:47.928 UTC [msp/identity] newIdentity -> DEBU 243 Creating identity instance for ID &{Orgorderer1MSP 1cbf17f7b537f919f5b81b36a0618fb9f22831f12e5de09f9539a1f0e4b91099} 2017-11-24 11:17:47.928 UTC [msp] SatisfiesPrincipal -> DEBU 244 Checking if identity satisfies MEMBER role for Orgorderer1MSP 2017-11-24 11:17:47.928 UTC [msp] Validate -> DEBU 245 MSP Orgorderer1MSP validating identity 2017-11-24 11:17:47.928 UTC [cauthdsl] func2 -> DEBU 246 0xc42012d420 principal matched by identity 0 2017-11-24 11:17:47.928 UTC [msp/identity] Verify -> DEBU 247 Verify: digest = 00000000 83 f0 db e0 ba ce 3f f2 c9 46 05 8c 01 67 3c 51 |......?..F...g DEBU 248 Verify: sig = 00000000 30 44 02 20 7b da 0a 5f a4 97 07 d2 63 7c 5e b6 |0D. {.._....c|^.| 00000010 4a f9 09 3e 42 64 40 3f 3e f3 21 14 6d e4 d2 00 |J..>Bd@?>.!.m...| 00000020 a7 6c 8b f4 02 20 45 7a 07 a7 42 b3 19 b0 6d 93 |.l... Ez..B...m.| 00000030 d5 2b 8b 69 44 df 76 f6 1f 02 a6 44 23 dc bf dd |.+.iD.v....D#...| 00000040 72 18 7a 95 bf cc |r.z...| 2017-11-24 11:17:47.929 UTC [cauthdsl] func2 -> DEBU 249 0xc42012d420 principal evaluation succeeds for identity 0 2017-11-24 11:17:47.929 UTC [cauthdsl] func1 -> DEBU 24a 0xc42012d420 gate 1511522267928412510 evaluation succeeds 2017-11-24 11:17:47.929 UTC [orderer/common/sigfilter] Apply -> DEBU 24b Forwarding validly signed message for policy &{%!s(*common.ImplicitMetaPolicy=&{Writers 0}) %!s(int=1) [%!s(*policies.implicitMetaPolicy=&{0xc4203ac440 1 [0xc42012c530]}) Writers]} 2017-11-24 11:17:47.929 UTC [msp] GetLocalMSP -> DEBU 24c Returning existing local MSP 2017-11-24 11:17:47.929 UTC [msp] GetDefaultSigningIdentity -> DEBU 24d Obtaining default signing identity 2017-11-24 11:17:47.929 UTC [msp] GetLocalMSP -> DEBU 24e Returning existing local MSP 2017-11-24 11:17:47.929 UTC [msp] GetDefaultSigningIdentity -> DEBU 24f Obtaining default signing identity 2017-11-24 11:17:47.929 UTC [msp/identity] Sign -> DEBU 250 Sign: plaintext: 0ABA060A1508011A0608DBFFDFD00522...41646D696E7310021A0641646D696E73 2017-11-24 11:17:47.929 UTC [msp/identity] Sign -> DEBU 251 Sign: digest: 5B05653B1AC3D6DC773DE8637CEEAFAC8004FA30ECB1929A187A244CC7E0FB44 2017-11-24 11:17:47.929 UTC [common/config] NewStandardValues -> DEBU 252 Initializing protos for *config.ChannelProtos 2017-11-24 11:17:47.929 UTC [common/config] initializeProtosStruct -> DEBU 253 Processing field: HashingAlgorithm 2017-11-24 11:17:47.929 UTC [common/config] initializeProtosStruct -> DEBU 254 Processing field: BlockDataHashingStructure 2017-11-24 11:17:47.929 UTC [common/config] initializeProtosStruct -> DEBU 255 Processing field: OrdererAddresses 2017-11-24 11:17:47.929 UTC [common/config] initializeProtosStruct -> DEBU 256 Processing field: Consortium 2017-11-24 11:17:47.929 UTC [common/configtx] addToMap -> DEBU 257 Adding to config map: [Groups] /Channel 2017-11-24 11:17:47.929 UTC [common/configtx] addToMap -> DEBU 258 Adding to config map: [Groups] /Channel/Orderer 2017-11-24 11:17:47.929 UTC [common/configtx] addToMap -> DEBU 259 Adding to config map: [Groups] /Channel/Orderer/Orgorderer1MSP 2017-11-24 11:17:47.929 UTC [common/configtx] addToMap -> DEBU 25a Adding to config map: [Values] /Channel/Orderer/Orgorderer1MSP/MSP 2017-11-24 11:17:47.929 UTC [common/configtx] addToMap -> DEBU 25b Adding to config map: [Policy] /Channel/Orderer/Orgorderer1MSP/Admins 2017-11-24 11:17:47.929 UTC [common/configtx] addToMap -> DEBU 25c Adding to config map: [Policy] /Channel/Orderer/Orgorderer1MSP/Readers 2017-11-24 11:17:47.929 UTC [common/configtx] addToMap -> DEBU 25d Adding to config map: [Policy] /Channel/Orderer/Orgorderer1MSP/Writers 2017-11-24 11:17:47.929 UTC [common/configtx] addToMap -> DEBU 25e Adding to config map: [Values] /Channel/Orderer/BatchTimeout 2017-11-24 11:17:47.929 UTC [common/configtx] addToMap -> DEBU 25f Adding to config map: [Values] /Channel/Orderer/ChannelRestrictions 2017-11-24 11:17:47.930 UTC [common/configtx] addToMap -> DEBU 260 Adding to config map: [Values] /Channel/Orderer/KafkaBrokers 2017-11-24 11:17:47.930 UTC [common/configtx] addToMap -> DEBU 261 Adding to config map: [Values] /Channel/Orderer/ConsensusType 2017-11-24 11:17:47.930 UTC [common/configtx] addToMap -> DEBU 262 Adding to config map: [Values] /Channel/Orderer/BatchSize 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 263 Adding to config map: [Policy] /Channel/Orderer/Readers 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 264 Adding to config map: [Policy] /Channel/Orderer/Writers 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 265 Adding to config map: [Policy] /Channel/Orderer/Admins 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 266 Adding to config map: [Policy] /Channel/Orderer/BlockValidation 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 267 Adding to config map: [Groups] /Channel/Application 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 268 Adding to config map: [Groups] /Channel/Application/Org1MSP 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 269 Adding to config map: [Values] /Channel/Application/Org1MSP/MSP 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 26a Adding to config map: [Policy] /Channel/Application/Org1MSP/Writers 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 26b Adding to config map: [Policy] /Channel/Application/Org1MSP/Admins 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 26c Adding to config map: [Policy] /Channel/Application/Org1MSP/Readers 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 26d Adding to config map: [Groups] /Channel/Application/Org2MSP 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 26e Adding to config map: [Values] /Channel/Application/Org2MSP/MSP 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 26f Adding to config map: [Policy] /Channel/Application/Org2MSP/Writers 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 270 Adding to config map: [Policy] /Channel/Application/Org2MSP/Admins 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 271 Adding to config map: [Policy] /Channel/Application/Org2MSP/Readers 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 272 Adding to config map: [Policy] /Channel/Application/ChannelCreationPolicy 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 273 Adding to config map: [Values] /Channel/Consortium 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 274 Adding to config map: [Values] /Channel/HashingAlgorithm 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 275 Adding to config map: [Values] /Channel/BlockDataHashingStructure 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 276 Adding to config map: [Values] /Channel/OrdererAddresses 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 277 Adding to config map: [Policy] /Channel/Readers 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 278 Adding to config map: [Policy] /Channel/Writers 2017-11-24 11:17:47.931 UTC [common/configtx] addToMap -> DEBU 279 Adding to config map: [Policy] /Channel/Admins 2017-11-24 11:17:47.931 UTC [common/configtx] processConfig -> DEBU 27a Beginning new config for channel mychannel 2017-11-24 11:17:47.931 UTC [common/config] NewStandardValues -> DEBU 27b Initializing protos for *config.ChannelProtos 2017-11-24 11:17:47.931 UTC [common/config] initializeProtosStruct -> DEBU 27c Processing field: HashingAlgorithm 2017-11-24 11:17:47.931 UTC [common/config] initializeProtosStruct -> DEBU 27d Processing field: BlockDataHashingStructure 2017-11-24 11:17:47.931 UTC [common/config] initializeProtosStruct -> DEBU 27e Processing field: OrdererAddresses 2017-11-24 11:17:47.931 UTC [common/config] initializeProtosStruct -> DEBU 27f Processing field: Consortium 2017-11-24 11:17:47.931 UTC [policies] ProposePolicy -> DEBU 280 Proposed new policy Readers for Channel 2017-11-24 11:17:47.931 UTC [policies] ProposePolicy -> DEBU 281 Proposed new policy Writers for Channel 2017-11-24 11:17:47.931 UTC [policies] ProposePolicy -> DEBU 282 Proposed new policy Admins for Channel 2017-11-24 11:17:47.931 UTC [common/config] NewStandardValues -> DEBU 283 Initializing protos for *struct {} 2017-11-24 11:17:47.931 UTC [policies] ProposePolicy -> DEBU 284 Proposed new policy ChannelCreationPolicy for Application 2017-11-24 11:17:47.931 UTC [common/config] NewStandardValues -> DEBU 285 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.931 UTC [common/config] initializeProtosStruct -> DEBU 286 Processing field: MSP 2017-11-24 11:17:47.931 UTC [common/config] NewStandardValues -> DEBU 287 Initializing protos for *config.ApplicationOrgProtos 2017-11-24 11:17:47.931 UTC [common/config] initializeProtosStruct -> DEBU 288 Processing field: AnchorPeers 2017-11-24 11:17:47.931 UTC [common/config] NewStandardValues -> DEBU 289 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.931 UTC [common/config] initializeProtosStruct -> DEBU 28a Processing field: MSP 2017-11-24 11:17:47.931 UTC [policies] ProposePolicy -> DEBU 28b Proposed new policy Admins for Org1MSP 2017-11-24 11:17:47.931 UTC [policies] ProposePolicy -> DEBU 28c Proposed new policy Readers for Org1MSP 2017-11-24 11:17:47.931 UTC [policies] ProposePolicy -> DEBU 28d Proposed new policy Writers for Org1MSP 2017-11-24 11:17:47.931 UTC [common/config] NewStandardValues -> DEBU 28e Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.932 UTC [common/config] initializeProtosStruct -> DEBU 28f Processing field: MSP 2017-11-24 11:17:47.932 UTC [common/config] NewStandardValues -> DEBU 290 Initializing protos for *config.ApplicationOrgProtos 2017-11-24 11:17:47.932 UTC [common/config] initializeProtosStruct -> DEBU 291 Processing field: AnchorPeers 2017-11-24 11:17:47.932 UTC [common/config] NewStandardValues -> DEBU 292 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.932 UTC [common/config] initializeProtosStruct -> DEBU 293 Processing field: MSP 2017-11-24 11:17:47.932 UTC [policies] ProposePolicy -> DEBU 294 Proposed new policy Writers for Org2MSP 2017-11-24 11:17:47.932 UTC [policies] ProposePolicy -> DEBU 295 Proposed new policy Admins for Org2MSP 2017-11-24 11:17:47.932 UTC [policies] ProposePolicy -> DEBU 296 Proposed new policy Readers for Org2MSP 2017-11-24 11:17:47.932 UTC [common/config] NewStandardValues -> DEBU 297 Initializing protos for *config.OrdererProtos 2017-11-24 11:17:47.932 UTC [common/config] initializeProtosStruct -> DEBU 298 Processing field: ConsensusType 2017-11-24 11:17:47.932 UTC [common/config] initializeProtosStruct -> DEBU 299 Processing field: BatchSize 2017-11-24 11:17:47.932 UTC [common/config] initializeProtosStruct -> DEBU 29a Processing field: BatchTimeout 2017-11-24 11:17:47.932 UTC [common/config] initializeProtosStruct -> DEBU 29b Processing field: KafkaBrokers 2017-11-24 11:17:47.932 UTC [common/config] initializeProtosStruct -> DEBU 29c Processing field: ChannelRestrictions 2017-11-24 11:17:47.932 UTC [policies] ProposePolicy -> DEBU 29d Proposed new policy Admins for Orderer 2017-11-24 11:17:47.932 UTC [policies] ProposePolicy -> DEBU 29e Proposed new policy BlockValidation for Orderer 2017-11-24 11:17:47.932 UTC [policies] ProposePolicy -> DEBU 29f Proposed new policy Readers for Orderer 2017-11-24 11:17:47.932 UTC [policies] ProposePolicy -> DEBU 2a0 Proposed new policy Writers for Orderer 2017-11-24 11:17:47.932 UTC [common/config] NewStandardValues -> DEBU 2a1 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.932 UTC [common/config] initializeProtosStruct -> DEBU 2a2 Processing field: MSP 2017-11-24 11:17:47.932 UTC [policies] ProposePolicy -> DEBU 2a3 Proposed new policy Writers for Orgorderer1MSP 2017-11-24 11:17:47.932 UTC [policies] ProposePolicy -> DEBU 2a4 Proposed new policy Admins for Orgorderer1MSP 2017-11-24 11:17:47.932 UTC [policies] ProposePolicy -> DEBU 2a5 Proposed new policy Readers for Orgorderer1MSP 2017-11-24 11:17:47.932 UTC [common/config] Validate -> DEBU 2a6 Anchor peers for org Org1MSP are 2017-11-24 11:17:47.932 UTC [common/config] validateMSP -> DEBU 2a7 Setting up MSP for org Org1MSP 2017-11-24 11:17:47.932 UTC [msp] NewBccspMsp -> DEBU 2a8 Creating BCCSP-based MSP instance 2017-11-24 11:17:47.932 UTC [msp] Setup -> DEBU 2a9 Setting up MSP instance Org1MSP 2017-11-24 11:17:47.932 UTC [msp/identity] newIdentity -> DEBU 2aa Creating identity instance for ID &{Org1MSP 9de37b4a016558ca2dc03d96145faf3f514231e91ad73d9db11aee5c6ae60744} 2017-11-24 11:17:47.932 UTC [msp/identity] newIdentity -> DEBU 2ab Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:17:47.932 UTC [msp/identity] newIdentity -> DEBU 2ac Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:17:47.933 UTC [msp] Validate -> DEBU 2ad MSP Org1MSP validating identity 2017-11-24 11:17:47.933 UTC [common/config] Validate -> DEBU 2ae Anchor peers for org Org2MSP are 2017-11-24 11:17:47.933 UTC [common/config] validateMSP -> DEBU 2af Setting up MSP for org Org2MSP 2017-11-24 11:17:47.933 UTC [msp] NewBccspMsp -> DEBU 2b0 Creating BCCSP-based MSP instance 2017-11-24 11:17:47.933 UTC [msp] Setup -> DEBU 2b1 Setting up MSP instance Org2MSP 2017-11-24 11:17:47.933 UTC [msp/identity] newIdentity -> DEBU 2b2 Creating identity instance for ID &{Org2MSP da2fafa0c7c0e56b1826c9f427c475f4f28a74f42152b1c70b7340125c302885} 2017-11-24 11:17:47.933 UTC [msp/identity] newIdentity -> DEBU 2b3 Creating identity instance for ID &{Org2MSP 09b6555908e39a6ebf1c956673f38f66c9082c424b9e64943d3a49ec2e455617} 2017-11-24 11:17:47.934 UTC [msp/identity] newIdentity -> DEBU 2b4 Creating identity instance for ID &{Org2MSP 09b6555908e39a6ebf1c956673f38f66c9082c424b9e64943d3a49ec2e455617} 2017-11-24 11:17:47.934 UTC [msp] Validate -> DEBU 2b5 MSP Org2MSP validating identity 2017-11-24 11:17:47.934 UTC [common/config] validateMSP -> DEBU 2b6 Setting up MSP for org Orgorderer1MSP 2017-11-24 11:17:47.934 UTC [msp] NewBccspMsp -> DEBU 2b7 Creating BCCSP-based MSP instance 2017-11-24 11:17:47.934 UTC [msp] Setup -> DEBU 2b8 Setting up MSP instance Orgorderer1MSP 2017-11-24 11:17:47.934 UTC [msp/identity] newIdentity -> DEBU 2b9 Creating identity instance for ID &{Orgorderer1MSP f879c2ec0ac3215b0a2042a3073b43e0db0f66a60e2c094b1f9b1941273f0d0d} 2017-11-24 11:17:47.935 UTC [msp/identity] newIdentity -> DEBU 2ba Creating identity instance for ID &{Orgorderer1MSP 8da4e1d96dad42b4e45a7323b55ddfc8af2280460c23fb4e66b45f4466435299} 2017-11-24 11:17:47.935 UTC [msp/identity] newIdentity -> DEBU 2bb Creating identity instance for ID &{Orgorderer1MSP 8da4e1d96dad42b4e45a7323b55ddfc8af2280460c23fb4e66b45f4466435299} 2017-11-24 11:17:47.935 UTC [msp] Validate -> DEBU 2bc MSP Orgorderer1MSP validating identity 2017-11-24 11:17:47.936 UTC [msp] Setup -> DEBU 2bd Setting up the MSP manager (3 msps) 2017-11-24 11:17:47.936 UTC [msp] Setup -> DEBU 2be MSP manager setup complete, setup 3 msps 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2bf Returning policy Admins for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2c0 In commit adding relative sub-policy Org1MSP/Admins to Application 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2c1 Returning policy Readers for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2c2 In commit adding relative sub-policy Org1MSP/Readers to Application 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2c3 Returning policy Writers for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2c4 In commit adding relative sub-policy Org1MSP/Writers to Application 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2c5 Returning policy Readers for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2c6 In commit adding relative sub-policy Org2MSP/Readers to Application 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2c7 Returning policy Writers for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2c8 In commit adding relative sub-policy Org2MSP/Writers to Application 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2c9 Returning policy Admins for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2ca In commit adding relative sub-policy Org2MSP/Admins to Application 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2cb Returning policy Admins for evaluation 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2cc Returning policy Admins for evaluation 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2cd Returning policy Writers for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2ce In commit adding relative sub-policy Orgorderer1MSP/Writers to Orderer 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2cf Returning policy Admins for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2d0 In commit adding relative sub-policy Orgorderer1MSP/Admins to Orderer 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2d1 Returning policy Readers for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2d2 In commit adding relative sub-policy Orgorderer1MSP/Readers to Orderer 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2d3 Returning policy Admins for evaluation 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2d4 Returning policy Writers for evaluation 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2d5 Returning policy Readers for evaluation 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2d6 Returning policy Writers for evaluation 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2d7 Returning policy Org2MSP/Readers for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2d8 In commit adding relative sub-policy Application/Org2MSP/Readers to Channel 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2d9 Returning policy Org2MSP/Writers for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2da In commit adding relative sub-policy Application/Org2MSP/Writers to Channel 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2db Returning policy Org2MSP/Admins for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2dc In commit adding relative sub-policy Application/Org2MSP/Admins to Channel 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2dd Returning policy ChannelCreationPolicy for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2de In commit adding relative sub-policy Application/ChannelCreationPolicy to Channel 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2df Returning policy Org1MSP/Admins for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2e0 In commit adding relative sub-policy Application/Org1MSP/Admins to Channel 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2e1 Returning policy Org1MSP/Readers for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2e2 In commit adding relative sub-policy Application/Org1MSP/Readers to Channel 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2e3 Returning policy Org1MSP/Writers for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2e4 In commit adding relative sub-policy Application/Org1MSP/Writers to Channel 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2e5 Returning policy Orgorderer1MSP/Writers for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2e6 In commit adding relative sub-policy Orderer/Orgorderer1MSP/Writers to Channel 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2e7 Returning policy Orgorderer1MSP/Admins for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2e8 In commit adding relative sub-policy Orderer/Orgorderer1MSP/Admins to Channel 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2e9 Returning policy Orgorderer1MSP/Readers for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2ea In commit adding relative sub-policy Orderer/Orgorderer1MSP/Readers to Channel 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2eb Returning policy Admins for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2ec In commit adding relative sub-policy Orderer/Admins to Channel 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2ed Returning policy BlockValidation for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2ee In commit adding relative sub-policy Orderer/BlockValidation to Channel 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2ef Returning policy Readers for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2f0 In commit adding relative sub-policy Orderer/Readers to Channel 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2f1 Returning policy Writers for evaluation 2017-11-24 11:17:47.936 UTC [policies] CommitProposals -> DEBU 2f2 In commit adding relative sub-policy Orderer/Writers to Channel 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2f3 Returning dummy reject all policy because Readers could not be found in /Application/Readers 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2f4 Returning policy Readers for evaluation 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2f5 Returning dummy reject all policy because Writers could not be found in /Application/Writers 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2f6 Returning policy Writers for evaluation 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2f7 Returning dummy reject all policy because Admins could not be found in /Application/Admins 2017-11-24 11:17:47.936 UTC [policies] GetPolicy -> DEBU 2f8 Returning policy Admins for evaluation 2017-11-24 11:17:47.936 UTC [common/configtx] addToMap -> DEBU 2f9 Adding to config map: [Groups] /Channel 2017-11-24 11:17:47.936 UTC [common/configtx] addToMap -> DEBU 2fa Adding to config map: [Groups] /Channel/Application 2017-11-24 11:17:47.937 UTC [common/configtx] addToMap -> DEBU 2fb Adding to config map: [Groups] /Channel/Application/Org2MSP 2017-11-24 11:17:47.937 UTC [common/configtx] addToMap -> DEBU 2fc Adding to config map: [Groups] /Channel/Application/Org1MSP 2017-11-24 11:17:47.937 UTC [common/configtx] addToMap -> DEBU 2fd Adding to config map: [Values] /Channel/Consortium 2017-11-24 11:17:47.937 UTC [common/configtx] addToMap -> DEBU 2fe Adding to config map: [Groups] /Channel 2017-11-24 11:17:47.937 UTC [common/configtx] addToMap -> DEBU 2ff Adding to config map: [Groups] /Channel/Application 2017-11-24 11:17:47.937 UTC [common/configtx] addToMap -> DEBU 300 Adding to config map: [Groups] /Channel/Application/Org2MSP 2017-11-24 11:17:47.937 UTC [common/configtx] addToMap -> DEBU 301 Adding to config map: [Groups] /Channel/Application/Org1MSP 2017-11-24 11:17:47.937 UTC [common/configtx] addToMap -> DEBU 302 Adding to config map: [Policy] /Channel/Application/Admins 2017-11-24 11:17:47.937 UTC [common/configtx] addToMap -> DEBU 303 Adding to config map: [Policy] /Channel/Application/Writers 2017-11-24 11:17:47.937 UTC [common/configtx] addToMap -> DEBU 304 Adding to config map: [Policy] /Channel/Application/Readers 2017-11-24 11:17:47.937 UTC [common/configtx] addToMap -> DEBU 305 Adding to config map: [Values] /Channel/Consortium 2017-11-24 11:17:47.937 UTC [policies] GetPolicy -> DEBU 306 Returning policy ChannelCreationPolicy for evaluation 2017-11-24 11:17:47.937 UTC [cauthdsl] func1 -> DEBU 307 0xc42012ca30 gate 1511522267937357096 evaluation starts 2017-11-24 11:17:47.937 UTC [cauthdsl] func2 -> DEBU 308 0xc42012ca30 signed by 0 principal evaluation starts (used [false]) 2017-11-24 11:17:47.937 UTC [cauthdsl] func2 -> DEBU 309 0xc42012ca30 processing identity 0 with bytes of 0a074f7267314d535012cf052d2d2d2d2d424547494e202d2d2d2d2d0a4d49494239544343415a756741774942416749514e664c46555972685a5a72476279495969417258697a414b42676771686b6a4f50515144416a42624d5173770a435159445651514745774a56557a45544d4245474131554543424d4b5132467361575a76636d3570595445574d4251474131554542784d4e5532467549455a790a5957356a61584e6a627a454e4d4173474131554543684d4562334a6e4d5445514d4134474131554541784d485932457562334a6e4d544165467730784e7a45780a4d6a51784d54417a4d7a5a61467730794e7a45784d6a49784d54417a4d7a5a614d453878437a414a42674e5642415954416c56544d524d7745515944565151490a45777044595778705a6d3979626d6c684d52597746415944565151484577315459573467526e4a68626d4e7063324e764d524d774551594456515144444170420a5a473170626b4276636d63784d466b77457759484b6f5a497a6a3043415159494b6f5a497a6a304441516344516741456154566341644f66596437516c6146420a6b38596c414b386c696548754f486f76746a38676e456638414e7663646b443149656d776f495961647a55666c496663433054513968332f6b6a2f2b746c436a0a477a6b756c614e4e4d45737744675944565230504151482f42415144416765414d41774741315564457745422f7751434d4141774b7759445652306a424351770a496f416745316a666f7041702f6f544e4c777138306f52533679524d30326d4b533433362b614a523070365948584177436759494b6f5a497a6a3045417749440a5341417752514968414c686a53624b54456238627450366a2f4332514f496e424a42594b51347066304f615670566c477073746c41694234364c516f414551320a74646d5350326b75597755506474417641784e2f6f3963366e57505363726d654d673d3d0a2d2d2d2d2d454e44202d2d2d2d2d0a 2017-11-24 11:17:47.937 UTC [msp/identity] newIdentity -> DEBU 30a Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:17:47.937 UTC [msp] SatisfiesPrincipal -> DEBU 30b Checking if identity satisfies ADMIN role for Org1MSP 2017-11-24 11:17:47.937 UTC [cauthdsl] func2 -> DEBU 30c 0xc42012ca30 principal matched by identity 0 2017-11-24 11:17:47.937 UTC [msp/identity] Verify -> DEBU 30d Verify: digest = 00000000 26 3f 5b 3c b8 01 7e b5 42 04 99 75 ee 4a ce 7c |&?[<..~.B..u.J.|| 00000010 ea 86 e1 c1 bc 5f 2e 87 89 18 8f 80 f2 c8 30 bc |....._........0.| 2017-11-24 11:17:47.937 UTC [msp/identity] Verify -> DEBU 30e Verify: sig = 00000000 30 45 02 21 00 82 80 1c 9b 9c 80 2e 86 09 ff 23 |0E.!...........#| 00000010 e3 11 92 d1 fa 58 d1 de ef 7b d7 2d 2d f9 88 fa |.....X...{.--...| 00000020 22 fb eb 8d 9c 02 20 71 ad 15 13 65 5e e1 eb 3c |"..... q...e^..<| 00000030 40 73 b9 31 f7 59 a8 5e 65 6d f3 c6 ff cd 00 b2 |@s.1.Y.^em......| 00000040 bd 9c 70 c5 f0 96 0e |..p....| 2017-11-24 11:17:47.937 UTC [cauthdsl] func2 -> DEBU 30f 0xc42012ca30 principal evaluation succeeds for identity 0 2017-11-24 11:17:47.937 UTC [cauthdsl] func1 -> DEBU 310 0xc42012ca30 gate 1511522267937357096 evaluation succeeds 2017-11-24 11:17:47.937 UTC [common/configtx] processConfig -> DEBU 311 Beginning new config for channel mychannel 2017-11-24 11:17:47.937 UTC [common/config] NewStandardValues -> DEBU 312 Initializing protos for *config.ChannelProtos 2017-11-24 11:17:47.937 UTC [common/config] initializeProtosStruct -> DEBU 313 Processing field: HashingAlgorithm 2017-11-24 11:17:47.937 UTC [common/config] initializeProtosStruct -> DEBU 314 Processing field: BlockDataHashingStructure 2017-11-24 11:17:47.938 UTC [common/config] initializeProtosStruct -> DEBU 315 Processing field: OrdererAddresses 2017-11-24 11:17:47.938 UTC [common/config] initializeProtosStruct -> DEBU 316 Processing field: Consortium 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 317 Proposed new policy Readers for Channel 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 318 Proposed new policy Writers for Channel 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 319 Proposed new policy Admins for Channel 2017-11-24 11:17:47.938 UTC [common/config] NewStandardValues -> DEBU 31a Initializing protos for *config.OrdererProtos 2017-11-24 11:17:47.938 UTC [common/config] initializeProtosStruct -> DEBU 31b Processing field: ConsensusType 2017-11-24 11:17:47.938 UTC [common/config] initializeProtosStruct -> DEBU 31c Processing field: BatchSize 2017-11-24 11:17:47.938 UTC [common/config] initializeProtosStruct -> DEBU 31d Processing field: BatchTimeout 2017-11-24 11:17:47.938 UTC [common/config] initializeProtosStruct -> DEBU 31e Processing field: KafkaBrokers 2017-11-24 11:17:47.938 UTC [common/config] initializeProtosStruct -> DEBU 31f Processing field: ChannelRestrictions 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 320 Proposed new policy Readers for Orderer 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 321 Proposed new policy Writers for Orderer 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 322 Proposed new policy Admins for Orderer 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 323 Proposed new policy BlockValidation for Orderer 2017-11-24 11:17:47.938 UTC [common/config] NewStandardValues -> DEBU 324 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.938 UTC [common/config] initializeProtosStruct -> DEBU 325 Processing field: MSP 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 326 Proposed new policy Readers for Orgorderer1MSP 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 327 Proposed new policy Writers for Orgorderer1MSP 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 328 Proposed new policy Admins for Orgorderer1MSP 2017-11-24 11:17:47.938 UTC [common/config] NewStandardValues -> DEBU 329 Initializing protos for *struct {} 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 32a Proposed new policy Writers for Application 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 32b Proposed new policy Readers for Application 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 32c Proposed new policy Admins for Application 2017-11-24 11:17:47.938 UTC [common/config] NewStandardValues -> DEBU 32d Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.938 UTC [common/config] initializeProtosStruct -> DEBU 32e Processing field: MSP 2017-11-24 11:17:47.938 UTC [common/config] NewStandardValues -> DEBU 32f Initializing protos for *config.ApplicationOrgProtos 2017-11-24 11:17:47.938 UTC [common/config] initializeProtosStruct -> DEBU 330 Processing field: AnchorPeers 2017-11-24 11:17:47.938 UTC [common/config] NewStandardValues -> DEBU 331 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.938 UTC [common/config] initializeProtosStruct -> DEBU 332 Processing field: MSP 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 333 Proposed new policy Writers for Org2MSP 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 334 Proposed new policy Admins for Org2MSP 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 335 Proposed new policy Readers for Org2MSP 2017-11-24 11:17:47.938 UTC [common/config] NewStandardValues -> DEBU 336 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.938 UTC [common/config] initializeProtosStruct -> DEBU 337 Processing field: MSP 2017-11-24 11:17:47.938 UTC [common/config] NewStandardValues -> DEBU 338 Initializing protos for *config.ApplicationOrgProtos 2017-11-24 11:17:47.938 UTC [common/config] initializeProtosStruct -> DEBU 339 Processing field: AnchorPeers 2017-11-24 11:17:47.938 UTC [common/config] NewStandardValues -> DEBU 33a Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.938 UTC [common/config] initializeProtosStruct -> DEBU 33b Processing field: MSP 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 33c Proposed new policy Admins for Org1MSP 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 33d Proposed new policy Readers for Org1MSP 2017-11-24 11:17:47.938 UTC [policies] ProposePolicy -> DEBU 33e Proposed new policy Writers for Org1MSP 2017-11-24 11:17:47.938 UTC [common/config] validateMSP -> DEBU 33f Setting up MSP for org Orgorderer1MSP 2017-11-24 11:17:47.938 UTC [msp] NewBccspMsp -> DEBU 340 Creating BCCSP-based MSP instance 2017-11-24 11:17:47.938 UTC [msp] Setup -> DEBU 341 Setting up MSP instance Orgorderer1MSP 2017-11-24 11:17:47.938 UTC [msp/identity] newIdentity -> DEBU 342 Creating identity instance for ID &{Orgorderer1MSP f879c2ec0ac3215b0a2042a3073b43e0db0f66a60e2c094b1f9b1941273f0d0d} 2017-11-24 11:17:47.938 UTC [msp/identity] newIdentity -> DEBU 343 Creating identity instance for ID &{Orgorderer1MSP 8da4e1d96dad42b4e45a7323b55ddfc8af2280460c23fb4e66b45f4466435299} 2017-11-24 11:17:47.939 UTC [msp/identity] newIdentity -> DEBU 344 Creating identity instance for ID &{Orgorderer1MSP 8da4e1d96dad42b4e45a7323b55ddfc8af2280460c23fb4e66b45f4466435299} 2017-11-24 11:17:47.939 UTC [msp] Validate -> DEBU 345 MSP Orgorderer1MSP validating identity 2017-11-24 11:17:47.939 UTC [common/config] Validate -> DEBU 346 Anchor peers for org Org2MSP are 2017-11-24 11:17:47.939 UTC [common/config] validateMSP -> DEBU 347 Setting up MSP for org Org2MSP 2017-11-24 11:17:47.939 UTC [msp] NewBccspMsp -> DEBU 348 Creating BCCSP-based MSP instance 2017-11-24 11:17:47.939 UTC [msp] Setup -> DEBU 349 Setting up MSP instance Org2MSP 2017-11-24 11:17:47.940 UTC [msp/identity] newIdentity -> DEBU 34a Creating identity instance for ID &{Org2MSP da2fafa0c7c0e56b1826c9f427c475f4f28a74f42152b1c70b7340125c302885} 2017-11-24 11:17:47.940 UTC [msp/identity] newIdentity -> DEBU 34b Creating identity instance for ID &{Org2MSP 09b6555908e39a6ebf1c956673f38f66c9082c424b9e64943d3a49ec2e455617} 2017-11-24 11:17:47.940 UTC [msp/identity] newIdentity -> DEBU 34c Creating identity instance for ID &{Org2MSP 09b6555908e39a6ebf1c956673f38f66c9082c424b9e64943d3a49ec2e455617} 2017-11-24 11:17:47.941 UTC [msp] Validate -> DEBU 34d MSP Org2MSP validating identity 2017-11-24 11:17:47.941 UTC [common/config] Validate -> DEBU 34e Anchor peers for org Org1MSP are 2017-11-24 11:17:47.941 UTC [common/config] validateMSP -> DEBU 34f Setting up MSP for org Org1MSP 2017-11-24 11:17:47.941 UTC [msp] NewBccspMsp -> DEBU 350 Creating BCCSP-based MSP instance 2017-11-24 11:17:47.941 UTC [msp] Setup -> DEBU 351 Setting up MSP instance Org1MSP 2017-11-24 11:17:47.941 UTC [msp/identity] newIdentity -> DEBU 352 Creating identity instance for ID &{Org1MSP 9de37b4a016558ca2dc03d96145faf3f514231e91ad73d9db11aee5c6ae60744} 2017-11-24 11:17:47.941 UTC [msp/identity] newIdentity -> DEBU 353 Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:17:47.941 UTC [msp/identity] newIdentity -> DEBU 354 Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:17:47.942 UTC [msp] Validate -> DEBU 355 MSP Org1MSP validating identity 2017-11-24 11:17:47.942 UTC [msp] Setup -> DEBU 356 Setting up the MSP manager (3 msps) 2017-11-24 11:17:47.942 UTC [msp] Setup -> DEBU 357 MSP manager setup complete, setup 3 msps 2017-11-24 11:17:47.942 UTC [common/configtx] addToMap -> DEBU 358 Adding to config map: [Groups] /Channel 2017-11-24 11:17:47.942 UTC [common/configtx] addToMap -> DEBU 359 Adding to config map: [Groups] /Channel/Application 2017-11-24 11:17:47.942 UTC [common/configtx] addToMap -> DEBU 35a Adding to config map: [Groups] /Channel/Application/Org2MSP 2017-11-24 11:17:47.942 UTC [common/configtx] addToMap -> DEBU 35b Adding to config map: [Groups] /Channel/Application/Org1MSP 2017-11-24 11:17:47.942 UTC [common/configtx] addToMap -> DEBU 35c Adding to config map: [Values] /Channel/Consortium 2017-11-24 11:17:47.942 UTC [common/configtx] addToMap -> DEBU 35d Adding to config map: [Groups] /Channel 2017-11-24 11:17:47.942 UTC [common/configtx] addToMap -> DEBU 35e Adding to config map: [Groups] /Channel/Application 2017-11-24 11:17:47.942 UTC [common/configtx] addToMap -> DEBU 35f Adding to config map: [Groups] /Channel/Application/Org2MSP 2017-11-24 11:17:47.942 UTC [common/configtx] addToMap -> DEBU 360 Adding to config map: [Groups] /Channel/Application/Org1MSP 2017-11-24 11:17:47.942 UTC [common/configtx] addToMap -> DEBU 361 Adding to config map: [Policy] /Channel/Application/Admins 2017-11-24 11:17:47.942 UTC [common/configtx] addToMap -> DEBU 362 Adding to config map: [Policy] /Channel/Application/Writers 2017-11-24 11:17:47.942 UTC [common/configtx] addToMap -> DEBU 363 Adding to config map: [Policy] /Channel/Application/Readers 2017-11-24 11:17:47.942 UTC [common/configtx] addToMap -> DEBU 364 Adding to config map: [Values] /Channel/Consortium 2017-11-24 11:17:47.942 UTC [policies] GetPolicy -> DEBU 365 Returning policy ChannelCreationPolicy for evaluation 2017-11-24 11:17:47.942 UTC [cauthdsl] func1 -> DEBU 366 0xc42012cf20 gate 1511522267942939978 evaluation starts 2017-11-24 11:17:47.942 UTC [cauthdsl] func2 -> DEBU 367 0xc42012cf20 signed by 0 principal evaluation starts (used [false]) 2017-11-24 11:17:47.942 UTC [cauthdsl] func2 -> DEBU 368 0xc42012cf20 processing identity 0 with bytes of 0a074f7267314d535012cf052d2d2d2d2d424547494e202d2d2d2d2d0a4d49494239544343415a756741774942416749514e664c46555972685a5a72476279495969417258697a414b42676771686b6a4f50515144416a42624d5173770a435159445651514745774a56557a45544d4245474131554543424d4b5132467361575a76636d3570595445574d4251474131554542784d4e5532467549455a790a5957356a61584e6a627a454e4d4173474131554543684d4562334a6e4d5445514d4134474131554541784d485932457562334a6e4d544165467730784e7a45780a4d6a51784d54417a4d7a5a61467730794e7a45784d6a49784d54417a4d7a5a614d453878437a414a42674e5642415954416c56544d524d7745515944565151490a45777044595778705a6d3979626d6c684d52597746415944565151484577315459573467526e4a68626d4e7063324e764d524d774551594456515144444170420a5a473170626b4276636d63784d466b77457759484b6f5a497a6a3043415159494b6f5a497a6a304441516344516741456154566341644f66596437516c6146420a6b38596c414b386c696548754f486f76746a38676e456638414e7663646b443149656d776f495961647a55666c496663433054513968332f6b6a2f2b746c436a0a477a6b756c614e4e4d45737744675944565230504151482f42415144416765414d41774741315564457745422f7751434d4141774b7759445652306a424351770a496f416745316a666f7041702f6f544e4c777138306f52533679524d30326d4b533433362b614a523070365948584177436759494b6f5a497a6a3045417749440a5341417752514968414c686a53624b54456238627450366a2f4332514f496e424a42594b51347066304f615670566c477073746c41694234364c516f414551320a74646d5350326b75597755506474417641784e2f6f3963366e57505363726d654d673d3d0a2d2d2d2d2d454e44202d2d2d2d2d0a 2017-11-24 11:17:47.943 UTC [msp/identity] newIdentity -> DEBU 369 Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:17:47.943 UTC [msp] SatisfiesPrincipal -> DEBU 36a Checking if identity satisfies ADMIN role for Org1MSP 2017-11-24 11:17:47.943 UTC [cauthdsl] func2 -> DEBU 36b 0xc42012cf20 principal matched by identity 0 2017-11-24 11:17:47.943 UTC [msp/identity] Verify -> DEBU 36c Verify: digest = 00000000 26 3f 5b 3c b8 01 7e b5 42 04 99 75 ee 4a ce 7c |&?[<..~.B..u.J.|| 00000010 ea 86 e1 c1 bc 5f 2e 87 89 18 8f 80 f2 c8 30 bc |....._........0.| 2017-11-24 11:17:47.943 UTC [msp/identity] Verify -> DEBU 36d Verify: sig = 00000000 30 45 02 21 00 82 80 1c 9b 9c 80 2e 86 09 ff 23 |0E.!...........#| 00000010 e3 11 92 d1 fa 58 d1 de ef 7b d7 2d 2d f9 88 fa |.....X...{.--...| 00000020 22 fb eb 8d 9c 02 20 71 ad 15 13 65 5e e1 eb 3c |"..... q...e^..<| 00000030 40 73 b9 31 f7 59 a8 5e 65 6d f3 c6 ff cd 00 b2 |@s.1.Y.^em......| 00000040 bd 9c 70 c5 f0 96 0e |..p....| 2017-11-24 11:17:47.943 UTC [cauthdsl] func2 -> DEBU 36e 0xc42012cf20 principal evaluation succeeds for identity 0 2017-11-24 11:17:47.943 UTC [cauthdsl] func1 -> DEBU 36f 0xc42012cf20 gate 1511522267942939978 evaluation succeeds 2017-11-24 11:17:47.943 UTC [common/configtx] processConfig -> DEBU 370 Beginning new config for channel mychannel 2017-11-24 11:17:47.943 UTC [common/config] NewStandardValues -> DEBU 371 Initializing protos for *config.ChannelProtos 2017-11-24 11:17:47.943 UTC [common/config] initializeProtosStruct -> DEBU 372 Processing field: HashingAlgorithm 2017-11-24 11:17:47.943 UTC [common/config] initializeProtosStruct -> DEBU 373 Processing field: BlockDataHashingStructure 2017-11-24 11:17:47.943 UTC [common/config] initializeProtosStruct -> DEBU 374 Processing field: OrdererAddresses 2017-11-24 11:17:47.943 UTC [common/config] initializeProtosStruct -> DEBU 375 Processing field: Consortium 2017-11-24 11:17:47.943 UTC [policies] ProposePolicy -> DEBU 376 Proposed new policy Readers for Channel 2017-11-24 11:17:47.943 UTC [policies] ProposePolicy -> DEBU 377 Proposed new policy Writers for Channel 2017-11-24 11:17:47.943 UTC [policies] ProposePolicy -> DEBU 378 Proposed new policy Admins for Channel 2017-11-24 11:17:47.943 UTC [common/config] NewStandardValues -> DEBU 379 Initializing protos for *config.OrdererProtos 2017-11-24 11:17:47.943 UTC [common/config] initializeProtosStruct -> DEBU 37a Processing field: ConsensusType 2017-11-24 11:17:47.943 UTC [common/config] initializeProtosStruct -> DEBU 37b Processing field: BatchSize 2017-11-24 11:17:47.943 UTC [common/config] initializeProtosStruct -> DEBU 37c Processing field: BatchTimeout 2017-11-24 11:17:47.943 UTC [common/config] initializeProtosStruct -> DEBU 37d Processing field: KafkaBrokers 2017-11-24 11:17:47.943 UTC [common/config] initializeProtosStruct -> DEBU 37e Processing field: ChannelRestrictions 2017-11-24 11:17:47.943 UTC [policies] ProposePolicy -> DEBU 37f Proposed new policy Readers for Orderer 2017-11-24 11:17:47.943 UTC [policies] ProposePolicy -> DEBU 380 Proposed new policy Writers for Orderer 2017-11-24 11:17:47.943 UTC [policies] ProposePolicy -> DEBU 381 Proposed new policy Admins for Orderer 2017-11-24 11:17:47.943 UTC [policies] ProposePolicy -> DEBU 382 Proposed new policy BlockValidation for Orderer 2017-11-24 11:17:47.943 UTC [common/config] NewStandardValues -> DEBU 383 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.943 UTC [common/config] initializeProtosStruct -> DEBU 384 Processing field: MSP 2017-11-24 11:17:47.943 UTC [policies] ProposePolicy -> DEBU 385 Proposed new policy Readers for Orgorderer1MSP 2017-11-24 11:17:47.943 UTC [policies] ProposePolicy -> DEBU 386 Proposed new policy Writers for Orgorderer1MSP 2017-11-24 11:17:47.943 UTC [policies] ProposePolicy -> DEBU 387 Proposed new policy Admins for Orgorderer1MSP 2017-11-24 11:17:47.943 UTC [common/config] NewStandardValues -> DEBU 388 Initializing protos for *struct {} 2017-11-24 11:17:47.943 UTC [policies] ProposePolicy -> DEBU 389 Proposed new policy Admins for Application 2017-11-24 11:17:47.943 UTC [policies] ProposePolicy -> DEBU 38a Proposed new policy Writers for Application 2017-11-24 11:17:47.943 UTC [policies] ProposePolicy -> DEBU 38b Proposed new policy Readers for Application 2017-11-24 11:17:47.943 UTC [common/config] NewStandardValues -> DEBU 38c Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.943 UTC [common/config] initializeProtosStruct -> DEBU 38d Processing field: MSP 2017-11-24 11:17:47.943 UTC [common/config] NewStandardValues -> DEBU 38e Initializing protos for *config.ApplicationOrgProtos 2017-11-24 11:17:47.943 UTC [common/config] initializeProtosStruct -> DEBU 38f Processing field: AnchorPeers 2017-11-24 11:17:47.943 UTC [common/config] NewStandardValues -> DEBU 390 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.943 UTC [common/config] initializeProtosStruct -> DEBU 391 Processing field: MSP 2017-11-24 11:17:47.943 UTC [policies] ProposePolicy -> DEBU 392 Proposed new policy Writers for Org2MSP 2017-11-24 11:17:47.943 UTC [policies] ProposePolicy -> DEBU 393 Proposed new policy Admins for Org2MSP 2017-11-24 11:17:47.943 UTC [policies] ProposePolicy -> DEBU 394 Proposed new policy Readers for Org2MSP 2017-11-24 11:17:47.943 UTC [common/config] NewStandardValues -> DEBU 395 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.943 UTC [common/config] initializeProtosStruct -> DEBU 396 Processing field: MSP 2017-11-24 11:17:47.943 UTC [common/config] NewStandardValues -> DEBU 397 Initializing protos for *config.ApplicationOrgProtos 2017-11-24 11:17:47.943 UTC [common/config] initializeProtosStruct -> DEBU 398 Processing field: AnchorPeers 2017-11-24 11:17:47.943 UTC [common/config] NewStandardValues -> DEBU 399 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.943 UTC [common/config] initializeProtosStruct -> DEBU 39a Processing field: MSP 2017-11-24 11:17:47.944 UTC [policies] ProposePolicy -> DEBU 39b Proposed new policy Writers for Org1MSP 2017-11-24 11:17:47.944 UTC [policies] ProposePolicy -> DEBU 39c Proposed new policy Admins for Org1MSP 2017-11-24 11:17:47.944 UTC [policies] ProposePolicy -> DEBU 39d Proposed new policy Readers for Org1MSP 2017-11-24 11:17:47.944 UTC [common/config] validateMSP -> DEBU 39e Setting up MSP for org Orgorderer1MSP 2017-11-24 11:17:47.944 UTC [msp] NewBccspMsp -> DEBU 39f Creating BCCSP-based MSP instance 2017-11-24 11:17:47.944 UTC [msp] Setup -> DEBU 3a0 Setting up MSP instance Orgorderer1MSP 2017-11-24 11:17:47.944 UTC [msp/identity] newIdentity -> DEBU 3a1 Creating identity instance for ID &{Orgorderer1MSP f879c2ec0ac3215b0a2042a3073b43e0db0f66a60e2c094b1f9b1941273f0d0d} 2017-11-24 11:17:47.944 UTC [msp/identity] newIdentity -> DEBU 3a2 Creating identity instance for ID &{Orgorderer1MSP 8da4e1d96dad42b4e45a7323b55ddfc8af2280460c23fb4e66b45f4466435299} 2017-11-24 11:17:47.944 UTC [msp/identity] newIdentity -> DEBU 3a3 Creating identity instance for ID &{Orgorderer1MSP 8da4e1d96dad42b4e45a7323b55ddfc8af2280460c23fb4e66b45f4466435299} 2017-11-24 11:17:47.945 UTC [msp] Validate -> DEBU 3a4 MSP Orgorderer1MSP validating identity 2017-11-24 11:17:47.945 UTC [common/config] Validate -> DEBU 3a5 Anchor peers for org Org2MSP are 2017-11-24 11:17:47.945 UTC [common/config] validateMSP -> DEBU 3a6 Setting up MSP for org Org2MSP 2017-11-24 11:17:47.945 UTC [msp] NewBccspMsp -> DEBU 3a7 Creating BCCSP-based MSP instance 2017-11-24 11:17:47.945 UTC [msp] Setup -> DEBU 3a8 Setting up MSP instance Org2MSP 2017-11-24 11:17:47.945 UTC [msp/identity] newIdentity -> DEBU 3a9 Creating identity instance for ID &{Org2MSP da2fafa0c7c0e56b1826c9f427c475f4f28a74f42152b1c70b7340125c302885} 2017-11-24 11:17:47.945 UTC [msp/identity] newIdentity -> DEBU 3aa Creating identity instance for ID &{Org2MSP 09b6555908e39a6ebf1c956673f38f66c9082c424b9e64943d3a49ec2e455617} 2017-11-24 11:17:47.945 UTC [msp/identity] newIdentity -> DEBU 3ab Creating identity instance for ID &{Org2MSP 09b6555908e39a6ebf1c956673f38f66c9082c424b9e64943d3a49ec2e455617} 2017-11-24 11:17:47.946 UTC [msp] Validate -> DEBU 3ac MSP Org2MSP validating identity 2017-11-24 11:17:47.946 UTC [common/config] Validate -> DEBU 3ad Anchor peers for org Org1MSP are 2017-11-24 11:17:47.946 UTC [common/config] validateMSP -> DEBU 3ae Setting up MSP for org Org1MSP 2017-11-24 11:17:47.946 UTC [msp] NewBccspMsp -> DEBU 3af Creating BCCSP-based MSP instance 2017-11-24 11:17:47.946 UTC [msp] Setup -> DEBU 3b0 Setting up MSP instance Org1MSP 2017-11-24 11:17:47.946 UTC [msp/identity] newIdentity -> DEBU 3b1 Creating identity instance for ID &{Org1MSP 9de37b4a016558ca2dc03d96145faf3f514231e91ad73d9db11aee5c6ae60744} 2017-11-24 11:17:47.946 UTC [msp/identity] newIdentity -> DEBU 3b2 Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:17:47.947 UTC [msp/identity] newIdentity -> DEBU 3b3 Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:17:47.947 UTC [msp] Validate -> DEBU 3b4 MSP Org1MSP validating identity 2017-11-24 11:17:47.947 UTC [msp] Setup -> DEBU 3b5 Setting up the MSP manager (3 msps) 2017-11-24 11:17:47.947 UTC [msp] Setup -> DEBU 3b6 MSP manager setup complete, setup 3 msps 2017-11-24 11:17:47.947 UTC [policies] GetPolicy -> DEBU 3b7 Returning policy Readers for evaluation 2017-11-24 11:17:47.947 UTC [policies] CommitProposals -> DEBU 3b8 In commit adding relative sub-policy Orgorderer1MSP/Readers to Orderer 2017-11-24 11:17:47.947 UTC [policies] GetPolicy -> DEBU 3b9 Returning policy Writers for evaluation 2017-11-24 11:17:47.947 UTC [policies] CommitProposals -> DEBU 3ba In commit adding relative sub-policy Orgorderer1MSP/Writers to Orderer 2017-11-24 11:17:47.947 UTC [policies] GetPolicy -> DEBU 3bb Returning policy Admins for evaluation 2017-11-24 11:17:47.947 UTC [policies] CommitProposals -> DEBU 3bc In commit adding relative sub-policy Orgorderer1MSP/Admins to Orderer 2017-11-24 11:17:47.947 UTC [policies] GetPolicy -> DEBU 3bd Returning policy Readers for evaluation 2017-11-24 11:17:47.947 UTC [policies] GetPolicy -> DEBU 3be Returning policy Writers for evaluation 2017-11-24 11:17:47.947 UTC [policies] GetPolicy -> DEBU 3bf Returning policy Admins for evaluation 2017-11-24 11:17:47.947 UTC [policies] GetPolicy -> DEBU 3c0 Returning policy Writers for evaluation 2017-11-24 11:17:47.947 UTC [policies] GetPolicy -> DEBU 3c1 Returning policy Writers for evaluation 2017-11-24 11:17:47.947 UTC [policies] CommitProposals -> DEBU 3c2 In commit adding relative sub-policy Org2MSP/Writers to Application 2017-11-24 11:17:47.947 UTC [policies] GetPolicy -> DEBU 3c3 Returning policy Admins for evaluation 2017-11-24 11:17:47.947 UTC [policies] CommitProposals -> DEBU 3c4 In commit adding relative sub-policy Org2MSP/Admins to Application 2017-11-24 11:17:47.947 UTC [policies] GetPolicy -> DEBU 3c5 Returning policy Readers for evaluation 2017-11-24 11:17:47.947 UTC [policies] CommitProposals -> DEBU 3c6 In commit adding relative sub-policy Org2MSP/Readers to Application 2017-11-24 11:17:47.947 UTC [policies] GetPolicy -> DEBU 3c7 Returning policy Admins for evaluation 2017-11-24 11:17:47.947 UTC [policies] CommitProposals -> DEBU 3c8 In commit adding relative sub-policy Org1MSP/Admins to Application 2017-11-24 11:17:47.947 UTC [policies] GetPolicy -> DEBU 3c9 Returning policy Readers for evaluation 2017-11-24 11:17:47.947 UTC [policies] CommitProposals -> DEBU 3ca In commit adding relative sub-policy Org1MSP/Readers to Application 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3cb Returning policy Writers for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3cc In commit adding relative sub-policy Org1MSP/Writers to Application 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3cd Returning policy Admins for evaluation 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3ce Returning policy Admins for evaluation 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3cf Returning policy Writers for evaluation 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3d0 Returning policy Writers for evaluation 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3d1 Returning policy Readers for evaluation 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3d2 Returning policy Readers for evaluation 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3d3 Returning policy BlockValidation for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3d4 In commit adding relative sub-policy Orderer/BlockValidation to Channel 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3d5 Returning policy Orgorderer1MSP/Readers for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3d6 In commit adding relative sub-policy Orderer/Orgorderer1MSP/Readers to Channel 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3d7 Returning policy Orgorderer1MSP/Writers for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3d8 In commit adding relative sub-policy Orderer/Orgorderer1MSP/Writers to Channel 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3d9 Returning policy Orgorderer1MSP/Admins for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3da In commit adding relative sub-policy Orderer/Orgorderer1MSP/Admins to Channel 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3db Returning policy Readers for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3dc In commit adding relative sub-policy Orderer/Readers to Channel 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3dd Returning policy Writers for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3de In commit adding relative sub-policy Orderer/Writers to Channel 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3df Returning policy Admins for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3e0 In commit adding relative sub-policy Orderer/Admins to Channel 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3e1 Returning policy Org1MSP/Writers for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3e2 In commit adding relative sub-policy Application/Org1MSP/Writers to Channel 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3e3 Returning policy Writers for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3e4 In commit adding relative sub-policy Application/Writers to Channel 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3e5 Returning policy Readers for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3e6 In commit adding relative sub-policy Application/Readers to Channel 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3e7 Returning policy Org2MSP/Writers for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3e8 In commit adding relative sub-policy Application/Org2MSP/Writers to Channel 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3e9 Returning policy Org2MSP/Admins for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3ea In commit adding relative sub-policy Application/Org2MSP/Admins to Channel 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3eb Returning policy Org2MSP/Readers for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3ec In commit adding relative sub-policy Application/Org2MSP/Readers to Channel 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3ed Returning policy Admins for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3ee In commit adding relative sub-policy Application/Admins to Channel 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3ef Returning policy Org1MSP/Admins for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3f0 In commit adding relative sub-policy Application/Org1MSP/Admins to Channel 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3f1 Returning policy Org1MSP/Readers for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3f2 In commit adding relative sub-policy Application/Org1MSP/Readers to Channel 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3f3 Returning policy Readers for evaluation 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3f4 Returning policy Readers for evaluation 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3f5 Returning policy Writers for evaluation 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3f6 Returning policy Writers for evaluation 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3f7 Returning policy Admins for evaluation 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3f8 Returning policy Admins for evaluation 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3f9 Returning policy Readers for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3fa As expected, current configuration has policy '/Channel/Readers' 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3fb Returning policy Writers for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3fc As expected, current configuration has policy '/Channel/Writers' 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3fd Returning policy Application/Readers for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 3fe As expected, current configuration has policy '/Channel/Application/Readers' 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 3ff Returning policy Application/Writers for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 400 As expected, current configuration has policy '/Channel/Application/Writers' 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 401 Returning policy Application/Admins for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 402 As expected, current configuration has policy '/Channel/Application/Admins' 2017-11-24 11:17:47.948 UTC [policies] GetPolicy -> DEBU 403 Returning policy Orderer/BlockValidation for evaluation 2017-11-24 11:17:47.948 UTC [policies] CommitProposals -> DEBU 404 As expected, current configuration has policy '/Channel/Orderer/BlockValidation' 2017-11-24 11:17:47.948 UTC [common/config] NewStandardValues -> DEBU 405 Initializing protos for *config.ChannelProtos 2017-11-24 11:17:47.948 UTC [common/config] initializeProtosStruct -> DEBU 406 Processing field: HashingAlgorithm 2017-11-24 11:17:47.948 UTC [common/config] initializeProtosStruct -> DEBU 407 Processing field: BlockDataHashingStructure 2017-11-24 11:17:47.948 UTC [common/config] initializeProtosStruct -> DEBU 408 Processing field: OrdererAddresses 2017-11-24 11:17:47.948 UTC [common/config] initializeProtosStruct -> DEBU 409 Processing field: Consortium 2017-11-24 11:17:47.948 UTC [common/configtx] addToMap -> DEBU 40a Adding to config map: [Groups] /Channel 2017-11-24 11:17:47.948 UTC [common/configtx] addToMap -> DEBU 40b Adding to config map: [Groups] /Channel/Orderer 2017-11-24 11:17:47.948 UTC [common/configtx] addToMap -> DEBU 40c Adding to config map: [Groups] /Channel/Orderer/Orgorderer1MSP 2017-11-24 11:17:47.948 UTC [common/configtx] addToMap -> DEBU 40d Adding to config map: [Values] /Channel/Orderer/Orgorderer1MSP/MSP 2017-11-24 11:17:47.948 UTC [common/configtx] addToMap -> DEBU 40e Adding to config map: [Policy] /Channel/Orderer/Orgorderer1MSP/Readers 2017-11-24 11:17:47.948 UTC [common/configtx] addToMap -> DEBU 40f Adding to config map: [Policy] /Channel/Orderer/Orgorderer1MSP/Writers 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 410 Adding to config map: [Policy] /Channel/Orderer/Orgorderer1MSP/Admins 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 411 Adding to config map: [Values] /Channel/Orderer/ChannelRestrictions 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 412 Adding to config map: [Values] /Channel/Orderer/KafkaBrokers 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 413 Adding to config map: [Values] /Channel/Orderer/ConsensusType 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 414 Adding to config map: [Values] /Channel/Orderer/BatchSize 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 415 Adding to config map: [Values] /Channel/Orderer/BatchTimeout 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 416 Adding to config map: [Policy] /Channel/Orderer/Readers 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 417 Adding to config map: [Policy] /Channel/Orderer/Writers 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 418 Adding to config map: [Policy] /Channel/Orderer/Admins 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 419 Adding to config map: [Policy] /Channel/Orderer/BlockValidation 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 41a Adding to config map: [Groups] /Channel/Application 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 41b Adding to config map: [Groups] /Channel/Application/Org2MSP 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 41c Adding to config map: [Values] /Channel/Application/Org2MSP/MSP 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 41d Adding to config map: [Policy] /Channel/Application/Org2MSP/Readers 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 41e Adding to config map: [Policy] /Channel/Application/Org2MSP/Writers 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 41f Adding to config map: [Policy] /Channel/Application/Org2MSP/Admins 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 420 Adding to config map: [Groups] /Channel/Application/Org1MSP 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 421 Adding to config map: [Values] /Channel/Application/Org1MSP/MSP 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 422 Adding to config map: [Policy] /Channel/Application/Org1MSP/Writers 2017-11-24 11:17:47.949 UTC [common/configtx] addToMap -> DEBU 423 Adding to config map: [Policy] /Channel/Application/Org1MSP/Admins 2017-11-24 11:17:47.950 UTC [common/configtx] addToMap -> DEBU 424 Adding to config map: [Policy] /Channel/Application/Org1MSP/Readers 2017-11-24 11:17:47.950 UTC [common/configtx] addToMap -> DEBU 425 Adding to config map: [Policy] /Channel/Application/Writers 2017-11-24 11:17:47.950 UTC [common/configtx] addToMap -> DEBU 426 Adding to config map: [Policy] /Channel/Application/Readers 2017-11-24 11:17:47.950 UTC [common/configtx] addToMap -> DEBU 427 Adding to config map: [Policy] /Channel/Application/Admins 2017-11-24 11:17:47.950 UTC [common/configtx] addToMap -> DEBU 428 Adding to config map: [Values] /Channel/Consortium 2017-11-24 11:17:47.950 UTC [common/configtx] addToMap -> DEBU 429 Adding to config map: [Values] /Channel/BlockDataHashingStructure 2017-11-24 11:17:47.950 UTC [common/configtx] addToMap -> DEBU 42a Adding to config map: [Values] /Channel/OrdererAddresses 2017-11-24 11:17:47.950 UTC [common/configtx] addToMap -> DEBU 42b Adding to config map: [Values] /Channel/HashingAlgorithm 2017-11-24 11:17:47.950 UTC [common/configtx] addToMap -> DEBU 42c Adding to config map: [Policy] /Channel/Admins 2017-11-24 11:17:47.950 UTC [common/configtx] addToMap -> DEBU 42d Adding to config map: [Policy] /Channel/Readers 2017-11-24 11:17:47.950 UTC [common/configtx] addToMap -> DEBU 42e Adding to config map: [Policy] /Channel/Writers 2017-11-24 11:17:47.950 UTC [common/configtx] processConfig -> DEBU 42f Beginning new config for channel mychannel 2017-11-24 11:17:47.950 UTC [common/config] NewStandardValues -> DEBU 430 Initializing protos for *config.ChannelProtos 2017-11-24 11:17:47.950 UTC [common/config] initializeProtosStruct -> DEBU 431 Processing field: HashingAlgorithm 2017-11-24 11:17:47.950 UTC [common/config] initializeProtosStruct -> DEBU 432 Processing field: BlockDataHashingStructure 2017-11-24 11:17:47.950 UTC [common/config] initializeProtosStruct -> DEBU 433 Processing field: OrdererAddresses 2017-11-24 11:17:47.950 UTC [common/config] initializeProtosStruct -> DEBU 434 Processing field: Consortium 2017-11-24 11:17:47.950 UTC [policies] ProposePolicy -> DEBU 435 Proposed new policy Admins for Channel 2017-11-24 11:17:47.950 UTC [policies] ProposePolicy -> DEBU 436 Proposed new policy Readers for Channel 2017-11-24 11:17:47.950 UTC [policies] ProposePolicy -> DEBU 437 Proposed new policy Writers for Channel 2017-11-24 11:17:47.950 UTC [common/config] NewStandardValues -> DEBU 438 Initializing protos for *config.OrdererProtos 2017-11-24 11:17:47.950 UTC [common/config] initializeProtosStruct -> DEBU 439 Processing field: ConsensusType 2017-11-24 11:17:47.950 UTC [common/config] initializeProtosStruct -> DEBU 43a Processing field: BatchSize 2017-11-24 11:17:47.950 UTC [common/config] initializeProtosStruct -> DEBU 43b Processing field: BatchTimeout 2017-11-24 11:17:47.950 UTC [common/config] initializeProtosStruct -> DEBU 43c Processing field: KafkaBrokers 2017-11-24 11:17:47.951 UTC [common/config] initializeProtosStruct -> DEBU 43d Processing field: ChannelRestrictions 2017-11-24 11:17:47.951 UTC [policies] ProposePolicy -> DEBU 43e Proposed new policy BlockValidation for Orderer 2017-11-24 11:17:47.951 UTC [policies] ProposePolicy -> DEBU 43f Proposed new policy Readers for Orderer 2017-11-24 11:17:47.951 UTC [policies] ProposePolicy -> DEBU 440 Proposed new policy Writers for Orderer 2017-11-24 11:17:47.951 UTC [policies] ProposePolicy -> DEBU 441 Proposed new policy Admins for Orderer 2017-11-24 11:17:47.951 UTC [common/config] NewStandardValues -> DEBU 442 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.951 UTC [common/config] initializeProtosStruct -> DEBU 443 Processing field: MSP 2017-11-24 11:17:47.951 UTC [policies] ProposePolicy -> DEBU 444 Proposed new policy Readers for Orgorderer1MSP 2017-11-24 11:17:47.951 UTC [policies] ProposePolicy -> DEBU 445 Proposed new policy Writers for Orgorderer1MSP 2017-11-24 11:17:47.951 UTC [policies] ProposePolicy -> DEBU 446 Proposed new policy Admins for Orgorderer1MSP 2017-11-24 11:17:47.951 UTC [common/config] NewStandardValues -> DEBU 447 Initializing protos for *struct {} 2017-11-24 11:17:47.951 UTC [policies] ProposePolicy -> DEBU 448 Proposed new policy Admins for Application 2017-11-24 11:17:47.951 UTC [policies] ProposePolicy -> DEBU 449 Proposed new policy Writers for Application 2017-11-24 11:17:47.951 UTC [policies] ProposePolicy -> DEBU 44a Proposed new policy Readers for Application 2017-11-24 11:17:47.951 UTC [common/config] NewStandardValues -> DEBU 44b Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.951 UTC [common/config] initializeProtosStruct -> DEBU 44c Processing field: MSP 2017-11-24 11:17:47.951 UTC [common/config] NewStandardValues -> DEBU 44d Initializing protos for *config.ApplicationOrgProtos 2017-11-24 11:17:47.951 UTC [common/config] initializeProtosStruct -> DEBU 44e Processing field: AnchorPeers 2017-11-24 11:17:47.951 UTC [common/config] NewStandardValues -> DEBU 44f Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.951 UTC [common/config] initializeProtosStruct -> DEBU 450 Processing field: MSP 2017-11-24 11:17:47.951 UTC [policies] ProposePolicy -> DEBU 451 Proposed new policy Admins for Org1MSP 2017-11-24 11:17:47.951 UTC [policies] ProposePolicy -> DEBU 452 Proposed new policy Readers for Org1MSP 2017-11-24 11:17:47.951 UTC [policies] ProposePolicy -> DEBU 453 Proposed new policy Writers for Org1MSP 2017-11-24 11:17:47.951 UTC [common/config] NewStandardValues -> DEBU 454 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.951 UTC [common/config] initializeProtosStruct -> DEBU 455 Processing field: MSP 2017-11-24 11:17:47.951 UTC [common/config] NewStandardValues -> DEBU 456 Initializing protos for *config.ApplicationOrgProtos 2017-11-24 11:17:47.951 UTC [common/config] initializeProtosStruct -> DEBU 457 Processing field: AnchorPeers 2017-11-24 11:17:47.951 UTC [common/config] NewStandardValues -> DEBU 458 Initializing protos for *config.OrganizationProtos 2017-11-24 11:17:47.951 UTC [common/config] initializeProtosStruct -> DEBU 459 Processing field: MSP 2017-11-24 11:17:47.951 UTC [policies] ProposePolicy -> DEBU 45a Proposed new policy Writers for Org2MSP 2017-11-24 11:17:47.951 UTC [policies] ProposePolicy -> DEBU 45b Proposed new policy Admins for Org2MSP 2017-11-24 11:17:47.951 UTC [policies] ProposePolicy -> DEBU 45c Proposed new policy Readers for Org2MSP 2017-11-24 11:17:47.951 UTC [common/config] validateMSP -> DEBU 45d Setting up MSP for org Orgorderer1MSP 2017-11-24 11:17:47.951 UTC [msp] NewBccspMsp -> DEBU 45e Creating BCCSP-based MSP instance 2017-11-24 11:17:47.951 UTC [msp] Setup -> DEBU 45f Setting up MSP instance Orgorderer1MSP 2017-11-24 11:17:47.951 UTC [msp/identity] newIdentity -> DEBU 460 Creating identity instance for ID &{Orgorderer1MSP f879c2ec0ac3215b0a2042a3073b43e0db0f66a60e2c094b1f9b1941273f0d0d} 2017-11-24 11:17:47.951 UTC [msp/identity] newIdentity -> DEBU 461 Creating identity instance for ID &{Orgorderer1MSP 8da4e1d96dad42b4e45a7323b55ddfc8af2280460c23fb4e66b45f4466435299} 2017-11-24 11:17:47.952 UTC [msp/identity] newIdentity -> DEBU 462 Creating identity instance for ID &{Orgorderer1MSP 8da4e1d96dad42b4e45a7323b55ddfc8af2280460c23fb4e66b45f4466435299} 2017-11-24 11:17:47.952 UTC [msp] Validate -> DEBU 463 MSP Orgorderer1MSP validating identity 2017-11-24 11:17:47.952 UTC [common/config] Validate -> DEBU 464 Anchor peers for org Org1MSP are 2017-11-24 11:17:47.952 UTC [common/config] validateMSP -> DEBU 465 Setting up MSP for org Org1MSP 2017-11-24 11:17:47.952 UTC [msp] NewBccspMsp -> DEBU 466 Creating BCCSP-based MSP instance 2017-11-24 11:17:47.952 UTC [msp] Setup -> DEBU 467 Setting up MSP instance Org1MSP 2017-11-24 11:17:47.952 UTC [msp/identity] newIdentity -> DEBU 468 Creating identity instance for ID &{Org1MSP 9de37b4a016558ca2dc03d96145faf3f514231e91ad73d9db11aee5c6ae60744} 2017-11-24 11:17:47.953 UTC [msp/identity] newIdentity -> DEBU 469 Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:17:47.953 UTC [msp/identity] newIdentity -> DEBU 46a Creating identity instance for ID &{Org1MSP 04fbb16ad2464128a0d3b435c5972ec2c5e756633898264a84f31aa5305e7e8e} 2017-11-24 11:17:47.953 UTC [msp] Validate -> DEBU 46b MSP Org1MSP validating identity 2017-11-24 11:17:47.953 UTC [common/config] Validate -> DEBU 46c Anchor peers for org Org2MSP are 2017-11-24 11:17:47.953 UTC [common/config] validateMSP -> DEBU 46d Setting up MSP for org Org2MSP 2017-11-24 11:17:47.953 UTC [msp] NewBccspMsp -> DEBU 46e Creating BCCSP-based MSP instance 2017-11-24 11:17:47.953 UTC [msp] Setup -> DEBU 46f Setting up MSP instance Org2MSP 2017-11-24 11:17:47.954 UTC [msp/identity] newIdentity -> DEBU 470 Creating identity instance for ID &{Org2MSP da2fafa0c7c0e56b1826c9f427c475f4f28a74f42152b1c70b7340125c302885} 2017-11-24 11:17:47.954 UTC [msp/identity] newIdentity -> DEBU 471 Creating identity instance for ID &{Org2MSP 09b6555908e39a6ebf1c956673f38f66c9082c424b9e64943d3a49ec2e455617} 2017-11-24 11:17:47.954 UTC [msp/identity] newIdentity -> DEBU 472 Creating identity instance for ID &{Org2MSP 09b6555908e39a6ebf1c956673f38f66c9082c424b9e64943d3a49ec2e455617} 2017-11-24 11:17:47.954 UTC [msp] Validate -> DEBU 473 MSP Org2MSP validating identity 2017-11-24 11:17:47.955 UTC [msp] Setup -> DEBU 474 Setting up the MSP manager (3 msps) 2017-11-24 11:17:47.955 UTC [msp] Setup -> DEBU 475 MSP manager setup complete, setup 3 msps 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 476 Returning policy Readers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 477 In commit adding relative sub-policy Orgorderer1MSP/Readers to Orderer 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 478 Returning policy Writers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 479 In commit adding relative sub-policy Orgorderer1MSP/Writers to Orderer 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 47a Returning policy Admins for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 47b In commit adding relative sub-policy Orgorderer1MSP/Admins to Orderer 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 47c Returning policy Writers for evaluation 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 47d Returning policy Readers for evaluation 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 47e Returning policy Writers for evaluation 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 47f Returning policy Admins for evaluation 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 480 Returning policy Admins for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 481 In commit adding relative sub-policy Org1MSP/Admins to Application 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 482 Returning policy Readers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 483 In commit adding relative sub-policy Org1MSP/Readers to Application 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 484 Returning policy Writers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 485 In commit adding relative sub-policy Org1MSP/Writers to Application 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 486 Returning policy Writers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 487 In commit adding relative sub-policy Org2MSP/Writers to Application 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 488 Returning policy Admins for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 489 In commit adding relative sub-policy Org2MSP/Admins to Application 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 48a Returning policy Readers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 48b In commit adding relative sub-policy Org2MSP/Readers to Application 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 48c Returning policy Admins for evaluation 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 48d Returning policy Admins for evaluation 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 48e Returning policy Writers for evaluation 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 48f Returning policy Writers for evaluation 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 490 Returning policy Readers for evaluation 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 491 Returning policy Readers for evaluation 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 492 Returning policy BlockValidation for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 493 In commit adding relative sub-policy Orderer/BlockValidation to Channel 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 494 Returning policy Readers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 495 In commit adding relative sub-policy Orderer/Readers to Channel 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 496 Returning policy Writers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 497 In commit adding relative sub-policy Orderer/Writers to Channel 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 498 Returning policy Admins for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 499 In commit adding relative sub-policy Orderer/Admins to Channel 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 49a Returning policy Orgorderer1MSP/Readers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 49b In commit adding relative sub-policy Orderer/Orgorderer1MSP/Readers to Channel 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 49c Returning policy Orgorderer1MSP/Writers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 49d In commit adding relative sub-policy Orderer/Orgorderer1MSP/Writers to Channel 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 49e Returning policy Orgorderer1MSP/Admins for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 49f In commit adding relative sub-policy Orderer/Orgorderer1MSP/Admins to Channel 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4a0 Returning policy Admins for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 4a1 In commit adding relative sub-policy Application/Admins to Channel 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4a2 Returning policy Org2MSP/Admins for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 4a3 In commit adding relative sub-policy Application/Org2MSP/Admins to Channel 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4a4 Returning policy Org2MSP/Readers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 4a5 In commit adding relative sub-policy Application/Org2MSP/Readers to Channel 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4a6 Returning policy Writers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 4a7 In commit adding relative sub-policy Application/Writers to Channel 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4a8 Returning policy Readers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 4a9 In commit adding relative sub-policy Application/Readers to Channel 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4aa Returning policy Org1MSP/Admins for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 4ab In commit adding relative sub-policy Application/Org1MSP/Admins to Channel 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4ac Returning policy Org1MSP/Readers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 4ad In commit adding relative sub-policy Application/Org1MSP/Readers to Channel 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4ae Returning policy Org1MSP/Writers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 4af In commit adding relative sub-policy Application/Org1MSP/Writers to Channel 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4b0 Returning policy Org2MSP/Writers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 4b1 In commit adding relative sub-policy Application/Org2MSP/Writers to Channel 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4b2 Returning policy Admins for evaluation 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4b3 Returning policy Admins for evaluation 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4b4 Returning policy Readers for evaluation 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4b5 Returning policy Readers for evaluation 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4b6 Returning policy Writers for evaluation 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4b7 Returning policy Writers for evaluation 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4b8 Returning policy Readers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 4b9 As expected, current configuration has policy '/Channel/Readers' 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4ba Returning policy Writers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 4bb As expected, current configuration has policy '/Channel/Writers' 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4bc Returning policy Application/Readers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 4bd As expected, current configuration has policy '/Channel/Application/Readers' 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4be Returning policy Application/Writers for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 4bf As expected, current configuration has policy '/Channel/Application/Writers' 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4c0 Returning policy Application/Admins for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 4c1 As expected, current configuration has policy '/Channel/Application/Admins' 2017-11-24 11:17:47.955 UTC [policies] GetPolicy -> DEBU 4c2 Returning policy Orderer/BlockValidation for evaluation 2017-11-24 11:17:47.955 UTC [policies] CommitProposals -> DEBU 4c3 As expected, current configuration has policy '/Channel/Orderer/BlockValidation' 2017-11-24 11:17:47.956 UTC [orderer/kafka] Enqueue -> DEBU 4c4 [channel: testchainid] Enqueueing envelope... 2017-11-24 11:17:47.956 UTC [orderer/kafka] Enqueue -> WARN 4c5 [channel: testchainid] Will not enqueue, consenter for this channel hasn't started yet 2017-11-24 11:17:47.956 UTC [orderer/main] func1 -> DEBU 4c6 Closing Broadcast stream 2017-11-24 11:17:47.958 UTC [orderer/common/deliver] Handle -> WARN 4c7 Error reading from stream: rpc error: code = Canceled desc = context canceled 2017-11-24 11:17:47.958 UTC [orderer/main] func1 -> DEBU 4c8 Closing Deliver stream 2017-11-24 11:21:01.894 UTC [orderer/kafka] try -> DEBU 4c9 [channel: testchainid] Attempting to post the CONNECT message... [sarama] 2017/11/24 11:21:01.894382 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:21:01.895520 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:21:01.895538 client.go:590: client/metadata retrying after 250ms... (3 attempts remaining) [sarama] 2017/11/24 11:21:02.145684 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:21:02.146849 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:21:02.146867 client.go:590: client/metadata retrying after 250ms... (2 attempts remaining) [sarama] 2017/11/24 11:21:02.397002 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:21:02.398245 client.go:610: client/metadata found some partitions to be leaderless [sarama] 2017/11/24 11:21:02.398265 client.go:590: client/metadata retrying after 250ms... (1 attempts remaining) [sarama] 2017/11/24 11:21:02.648398 client.go:599: client/metadata fetching metadata for [testchainid] from broker kafka3.kafka:9092 [sarama] 2017/11/24 11:21:02.649476 client.go:610: client/metadata found some partitions to be leaderless