Fabric SDK go instantiation chain code connection 7053 port waiting timeout

Error reporting ：

[fabsdk/fab] 2020/03/23 11:09:24 UTC - endpoint.(*DiscoveryWrapper).GetPeers -> DEBU Channel peer config for [grpcs://127.0.0.1:7051]: &fab.ChannelPeer{PeerChannelConfig:fab.PeerChannelConfig{EndorsingPeer:true, ChaincodeQuery:true, LedgerQuery:true, EventSource:true}, NetworkPeer:fab.NetworkPeer{PeerConfig:fab.PeerConfig{URL:"grpcs://127.0.0.1:7051", EventURL:"localhost:7053", GRPCOptions:map[string]interface {}{"allow-insecure":false, "ssl-target-name-override":"peer0.org1.example.com"}, TLSCACert:(*x509.Certificate)(0xc0001b2000)}, MSPID:"Org1MSP"}} [fabsdk/fab] 2020/03/23 11:09:24 UTC - lbp.(*RoundRobin).Choose -> DEBU Choosing peer at index 0 [fabsdk/fab] 2020/03/23 11:09:24 UTC - comm.(*params).SetHostOverride -> DEBU HostOverride: peer0.org1.example.com [fabsdk/fab] 2020/03/23 11:09:24 UTC - comm.(*params).SetFailFast -> DEBU FailFast: false [fabsdk/util] 2020/03/23 11:09:24 UTC - lazyref.(*Reference).setTimerRunning -> DEBU Timer started [fabsdk/util] 2020/03/23 11:09:24 UTC - lazyref.checkTimeStarted -> DEBU Starting timer [fabsdk/util] 2020/03/23 11:09:24 UTC - lazyref.checkTimeStarted -> DEBU Handling expiration... [fabsdk/util] 2020/03/23 11:09:24 UTC - lazyref.(*Reference).handleExpiration -> DEBU Invoking expiration handler [fabsdk/fab] 2020/03/23 11:09:24 UTC - membership.(*Ref).initializer.func1 -> DEBU Initializing membership reference... [fabsdk/fab] 2020/03/23 11:09:24 UTC - membership.(*Ref).initializer.func1 -> DEBU Got config block with number 0 have 0 [fabsdk/util] 2020/03/23 11:09:24 UTC - lazyref.(*Reference).ensureTimerStarted -> DEBU Timer is already running [fabsdk/util] 2020/03/23 11:09:24 UTC - lazyref.checkTimeStarted -> DEBU ... finished handling expiration. Setting expiration to 1m0s [fabsdk/util] 2020/03/23 11:09:24 UTC - lazyref.(*Reference).setTimerRunning -> DEBU Cannot start timer since timer is either already running or it is closed [fabsdk/util] 2020/03/23 11:09:24 UTC - lazyref.checkTimeStarted -> DEBU Timer is already running [fabsdk/fab] 2020/03/23 11:09:24 UTC - comm.(*params).SetKeepAliveParams -> DEBU KeepAliveParams: keepalive.ClientParameters{Time:0, Timeout:0, PermitWithoutStream:false} [fabsdk/fab] 2020/03/23 11:09:24 UTC - comm.(*params).SetCertificate -> DEBU setting certificate [subject: CN=tlsca.org1.example.com,O=org1.example.com,L=San Francisco,ST=California,C=US, serial: 97289392584299947279503782110623601434] [fabsdk/fab] 2020/03/23 11:09:24 UTC - comm.(*params).SetConnectTimeout -> DEBU ConnectTimeout: 15s [fabsdk/fab] 2020/03/23 11:09:24 UTC - comm.newDialOpts -> DEBU Creating a secure connection to [localhost:7053] with TLS HostOverride [peer0.org1.example.com] [fabsdk/fab] 2020/03/23 11:09:24 UTC - comm.(*CachingConnector).DialContext -> DEBU DialContext: localhost:7053 [fabsdk/fab] 2020/03/23 11:09:24 UTC - comm.(*CachingConnector).createConn -> DEBU creating connection [localhost:7053] [fabsdk/fab] 2020/03/23 11:09:24 UTC - comm.(*CachingConnector).createConn -> DEBU storing connection [localhost:7053] [fabsdk/fab] 2020/03/23 11:09:39 UTC - dispatcher.(*Dispatcher).HandleConnectEvent -> WARN error creating connection: could not connect to localhost:7053: dialing connection timed out [localhost:7053] [fabsdk/fab] 2020/03/23 11:09:39 UTC - dispatcher.(*Dispatcher).Start.func1 -> DEBU Listening for events... [fabsdk/fab] 2020/03/23 11:09:39 UTC - client.(*Client).connect -> DEBU ... got error in connection response: could not create client conn: could not connect to localhost:7053: dialing connection timed out [localhost:7053] Failed to instantiate chain code : error registering for TxStatus event: could not create client conn: could not connect to localhost:7053: dialing connection timed out [localhost:7053]

docker Environmental Science

CONTAINER ID        IMAGE                                                                                                      COMMAND                  CREATED              STATUS              PORTS                              NAMES629652716ea4        dev-peer0.org1.example.com-simplecc-1.0-73860628030aa682d642a0f572633c445fd461a6c87f46b0c7a680b7e34134e6   "chaincode -peer.add…"   About a minute ago   Up About a minute                                      dev-peer0.org1.example.com-simplecc-1.06c7419f01d49        hyperledger/fabric-tools:1.4.6                                                                             "/bin/bash"              About a minute ago   Up About a minute                                      cli4c1c86a4bdff        hyperledger/fabric-peer:1.4.6                                                                              "peer node start"        About a minute ago   Up About a minute   0.0.0.0:7051-7053->7051-7053/tcp   peer0.org1.example.comd586727557cf        hyperledger/fabric-orderer:1.4.6                                                                           "orderer"                About a minute ago   Up About a minute   0.0.0.0:7050->7050/tcp             orderer.example.com

The network environment

tcp        0      0 ubuntu:domain           *:*                     LISTEN      -               tcp        0      0 localhost:ipp           *:*                     LISTEN      -               tcp6       0      0 [::]:7052               [::]:*                  LISTEN      -               tcp6       0      0 [::]:7053               [::]:*                  LISTEN      -               tcp6       0      0 ip6-localhost:ipp       [::]:*                  LISTEN      -               tcp6       0      0 [::]:7050               [::]:*                  LISTEN      -               tcp6       0      0 [::]:7051               [::]:*                  LISTEN      - 

Orderer Part of the log

2020-03-23 11:09:06.590 UTC [cauthdsl] func1 -> DEBU 565 0xc0002a1350 gate 1584961746590910650 evaluation starts2020-03-23 11:09:06.590 UTC [cauthdsl] func2 -> DEBU 566 0xc0002a1350 signed by 0 principal evaluation starts (used [false])2020-03-23 11:09:06.590 UTC [cauthdsl] func2 -> DEBU 567 0xc0002a1350 processing identity 0 with bytes of fd63402020-03-23 11:09:06.591 UTC [cauthdsl] func2 -> DEBU 568 0xc0002a1350 identity 0 does not satisfy principal: the identity is a member of a different MSP (expected OrdererMSP, got Org1MSP)2020-03-23 11:09:06.591 UTC [cauthdsl] func2 -> DEBU 569 0xc0002a1350 principal evaluation fails2020-03-23 11:09:06.591 UTC [cauthdsl] func1 -> DEBU 56a 0xc0002a1350 gate 1584961746590910650 evaluation fails2020-03-23 11:09:06.591 UTC [policies] Evaluate -> DEBU 56b Signature set did not satisfy policy /Channel/Orderer/OrdererOrg/Readers2020-03-23 11:09:06.591 UTC [policies] Evaluate -> DEBU 56c == Done Evaluating *cauthdsl.policy Policy /Channel/Orderer/OrdererOrg/Readers2020-03-23 11:09:06.591 UTC [policies] func1 -> DEBU 56d Evaluation Failed: Only 0 policies were satisfied, but needed 1 of [ OrdererOrg/Readers ]2020-03-23 11:09:06.591 UTC [policies] Evaluate -> DEBU 56e Signature set did not satisfy policy /Channel/Orderer/Readers2020-03-23 11:09:06.591 UTC [policies] Evaluate -> DEBU 56f == Done Evaluating *policies.implicitMetaPolicy Policy /Channel/Orderer/Readers2020-03-23 11:09:06.591 UTC [policies] Evaluate -> DEBU 570 == Evaluating *policies.implicitMetaPolicy Policy /Channel/Application/Readers ==2020-03-23 11:09:06.591 UTC [policies] Evaluate -> DEBU 571 This is an implicit meta policy, it will trigger other policy evaluations, whose failures may be benign2020-03-23 11:09:06.591 UTC [policies] Evaluate -> DEBU 572 == Evaluating *cauthdsl.policy Policy /Channel/Application/Org1MSP/Readers ==2020-03-23 11:09:06.591 UTC [cauthdsl] func1 -> DEBU 573 0xc0005ac6b0 gate 1584961746591312762 evaluation starts2020-03-23 11:09:06.591 UTC [cauthdsl] func2 -> DEBU 574 0xc0005ac6b0 signed by 0 principal evaluation starts (used [false])2020-03-23 11:09:06.591 UTC [cauthdsl] func2 -> DEBU 575 0xc0005ac6b0 processing identity 0 with bytes of fd63402020-03-23 11:09:06.591 UTC [msp] satisfiesPrincipalInternalV143 -> DEBU 576 Checking if identity has been named explicitly as an admin for Org1MSP2020-03-23 11:09:06.591 UTC [msp] satisfiesPrincipalInternalV143 -> DEBU 577 Checking if identity carries the admin ou for Org1MSP2020-03-23 11:09:06.591 UTC [msp] Validate -> DEBU 578 MSP Org1MSP validating identity2020-03-23 11:09:06.591 UTC [msp] getCertificationChain -> DEBU 579 MSP Org1MSP getting certification chain2020-03-23 11:09:06.591 UTC [msp] hasOURole -> DEBU 57a MSP Org1MSP checking if the identity is a client2020-03-23 11:09:06.591 UTC [msp] getCertificationChain -> DEBU 57b MSP Org1MSP getting certification chain2020-03-23 11:09:06.591 UTC [cauthdsl] func2 -> DEBU 57c 0xc0005ac6b0 identity 0 does not satisfy principal: The identity is not an admin under this MSP [Org1MSP]: The identity does not contain OU [ADMIN], MSP: [Org1MSP]2020-03-23 11:09:06.591 UTC [cauthdsl] func2 -> DEBU 57d 0xc0005ac6b0 principal evaluation fails2020-03-23 11:09:06.591 UTC [cauthdsl] func2 -> DEBU 57e 0xc0005ac6b0 signed by 1 principal evaluation starts (used [false])2020-03-23 11:09:06.591 UTC [cauthdsl] func2 -> DEBU 57f 0xc0005ac6b0 processing identity 0 with bytes of fd63402020-03-23 11:09:06.592 UTC [msp] satisfiesPrincipalInternalPreV13 -> DEBU 580 Checking if identity satisfies role [PEER] for Org1MSP2020-03-23 11:09:06.592 UTC [msp] Validate -> DEBU 581 MSP Org1MSP validating identity2020-03-23 11:09:06.592 UTC [msp] getCertificationChain -> DEBU 582 MSP Org1MSP getting certification chain2020-03-23 11:09:06.592 UTC [msp] hasOURole -> DEBU 583 MSP Org1MSP checking if the identity is a client2020-03-23 11:09:06.592 UTC [msp] getCertificationChain -> DEBU 584 MSP Org1MSP getting certification chain2020-03-23 11:09:06.592 UTC [cauthdsl] func2 -> DEBU 585 0xc0005ac6b0 principal matched by identity 02020-03-23 11:09:06.592 UTC [msp.identity] Verify -> DEBU 586 Verify: digest = 00000000  39 bb 88 42 e9 1b 3d 5b  78 56 70 3d 13 48 48 2a  |9..B..=[xVp=.HH*|00000010  5e e4 ad fc a0 6b e9 d9  b6 af 9e a9 6b 4b 72 af  |^....k......kKr.|2020-03-23 11:09:06.592 UTC [msp.identity] Verify -> DEBU 587 Verify: sig = 00000000  30 44 02 20 0f 4c b5 b3  71 95 3d bf 9d 48 ae 31  |0D. .L..q.=..H.1|00000010  93 4d 7f 80 62 d0 41 d2  ce 28 0d 1a 15 c7 34 47  |.M..b.A..(....4G|00000020  b9 a2 bb 79 02 20 13 ba  ea 7a 23 38 78 23 4f 63  |...y. ...z#8x#Oc|00000030  47 62 a2 bc f5 f1 59 0a  7c 17 b7 2c a5 6e 86 a6  |Gb....Y.|..,.n..|00000040  93 05 7a 94 e1 5a                                 |..z..Z|2020-03-23 11:09:06.592 UTC [cauthdsl] func2 -> DEBU 588 0xc0005ac6b0 principal evaluation succeeds for identity 02020-03-23 11:09:06.592 UTC [cauthdsl] func2 -> DEBU 589 0xc0005ac6b0 signed by 2 principal evaluation starts (used [true])2020-03-23 11:09:06.592 UTC [cauthdsl] func2 -> DEBU 58a 0xc0005ac6b0 skipping identity 0 because it has already been used2020-03-23 11:09:06.592 UTC [cauthdsl] func2 -> DEBU 58b 0xc0005ac6b0 principal evaluation fails2020-03-23 11:09:06.592 UTC [cauthdsl] func1 -> DEBU 58c 0xc0005ac6b0 gate 1584961746591312762 evaluation succeeds2020-03-23 11:09:06.592 UTC [policies] Evaluate -> DEBU 58d Signature set satisfies policy /Channel/Application/Org1MSP/Readers2020-03-23 11:09:06.592 UTC [policies] Evaluate -> DEBU 58e == Done Evaluating *cauthdsl.policy Policy /Channel/Application/Org1MSP/Readers2020-03-23 11:09:06.592 UTC [policies] Evaluate -> DEBU 58f Signature set satisfies policy /Channel/Application/Readers2020-03-23 11:09:06.592 UTC [policies] Evaluate -> DEBU 590 == Done Evaluating *policies.implicitMetaPolicy Policy /Channel/Application/Readers2020-03-23 11:09:06.592 UTC [policies] Evaluate -> DEBU 591 Signature set satisfies policy /Channel/Readers2020-03-23 11:09:06.592 UTC [policies] Evaluate -> DEBU 592 == Done Evaluating *policies.implicitMetaPolicy Policy /Channel/Readers2020-03-23 11:09:06.592 UTC [common.deliver] deliverBlocks -> DEBU 593 [channel: mychannel] Received seekInfo (0xc0004a4540) start:<specified:<number:1 > > stop:<specified:<number:18446744073709551615 > >  from 172.21.0.2:557002020-03-23 11:09:06.593 UTC [fsblkstorage] waitForBlock -> DEBU 594 Going to wait for newer blocks. maxAvailaBlockNumber=[0], waitForBlockNum=[1]2020-03-23 11:09:39.918 UTC [grpc] infof -> DEBU 595 transport: loopyWriter.run returning. connection error: desc = "transport is closing"

peer0.org1 Part of the log

2020-03-23 11:08:59.690 UTC [gossip.gossip] start -> INFO 013 Gossip instance peer0.org1.example.com:7051 started2020-03-23 11:08:59.691 UTC [sccapi] deploySysCC -> INFO 014 system chaincode lscc/(github.com/hyperledger/fabric/core/scc/lscc) deployed2020-03-23 11:08:59.692 UTC [cscc] Init -> INFO 015 Init CSCC2020-03-23 11:08:59.692 UTC [sccapi] deploySysCC -> INFO 016 system chaincode cscc/(github.com/hyperledger/fabric/core/scc/cscc) deployed2020-03-23 11:08:59.692 UTC [qscc] Init -> INFO 017 Init QSCC2020-03-23 11:08:59.692 UTC [sccapi] deploySysCC -> INFO 018 system chaincode qscc/(github.com/hyperledger/fabric/core/scc/qscc) deployed2020-03-23 11:08:59.692 UTC [sccapi] deploySysCC -> INFO 019 system chaincode (+lifecycle,github.com/hyperledger/fabric/core/chaincode/lifecycle) disabled2020-03-23 11:08:59.692 UTC [nodeCmd] serve -> INFO 01a Deployed system chaincodes2020-03-23 11:08:59.694 UTC [discovery] NewService -> INFO 01b Created with config TLS: true, authCacheMaxSize: 1000, authCachePurgeRatio: 0.7500002020-03-23 11:08:59.694 UTC [nodeCmd] registerDiscoveryService -> INFO 01c Discovery service activated2020-03-23 11:08:59.694 UTC [nodeCmd] serve -> INFO 01d Starting peer with ID=[name:"peer0.org1.example.com" ], network ID=[dev], address=[peer0.org1.example.com:7051]2020-03-23 11:08:59.694 UTC [nodeCmd] serve -> INFO 01e Started peer with ID=[name:"peer0.org1.example.com" ], network ID=[dev], address=[peer0.org1.example.com:7051]2020-03-23 11:08:59.695 UTC [kvledger] LoadPreResetHeight -> INFO 01f Loading prereset height from path [/var/hyperledger/production/ledgersData/chains]2020-03-23 11:08:59.695 UTC [fsblkstorage] LoadPreResetHeight -> INFO 020 Loading Pre-reset heights2020-03-23 11:08:59.695 UTC [fsblkstorage] preRestHtFiles -> INFO 021 Dir [/var/hyperledger/production/ledgersData/chains/chains] missing... exiting2020-03-23 11:08:59.695 UTC [fsblkstorage] LoadPreResetHeight -> INFO 022 Pre-reset heights loaded2020-03-23 11:08:59.695 UTC [nodeCmd] func7 -> INFO 023 Starting profiling server with listenAddress = 0.0.0.0:60602020-03-23 11:09:00.441 UTC [endorser] callChaincode -> INFO 024 [][0305b40d] Entry chaincode: name:"cscc" 2020-03-23 11:09:00.442 UTC [ledgermgmt] CreateLedger -> INFO 025 Creating ledger [mychannel] with genesis block2020-03-23 11:09:00.466 UTC [fsblkstorage] newBlockfileMgr -> INFO 026 Getting block information from block storage2020-03-23 11:09:00.547 UTC [kvledger] CommitWithPvtData -> INFO 027 [mychannel] Committed block [0] with 1 transaction(s) in 72ms (state_validation=0ms block_and_pvtdata_commit=53ms state_commit=9ms) commitHash=[]2020-03-23 11:09:00.556 UTC [ledgermgmt] CreateLedger -> INFO 028 Created ledger [mychannel] with genesis block2020-03-23 11:09:00.557 UTC [gossip.gossip] JoinChan -> INFO 029 Joining gossip network of channel mychannel with 1 organizations2020-03-23 11:09:00.557 UTC [gossip.gossip] learnAnchorPeers -> INFO 02a No configured anchor peers of Org1MSP for channel mychannel to learn about2020-03-23 11:09:00.577 UTC [gossip.state] NewGossipStateProvider -> INFO 02b Updating metadata information for channel mychannel, current ledger sequence is at = 0, next expected block is = 12020-03-23 11:09:00.578 UTC [sccapi] deploySysCC -> INFO 02c system chaincode lscc/mychannel(github.com/hyperledger/fabric/core/scc/lscc) deployed2020-03-23 11:09:00.578 UTC [cscc] Init -> INFO 02d Init CSCC2020-03-23 11:09:00.578 UTC [sccapi] deploySysCC -> INFO 02e system chaincode cscc/mychannel(github.com/hyperledger/fabric/core/scc/cscc) deployed2020-03-23 11:09:00.579 UTC [qscc] Init -> INFO 02f Init QSCC2020-03-23 11:09:00.579 UTC [sccapi] deploySysCC -> INFO 030 system chaincode qscc/mychannel(github.com/hyperledger/fabric/core/scc/qscc) deployed2020-03-23 11:09:00.579 UTC [sccapi] deploySysCC -> INFO 031 system chaincode (+lifecycle,github.com/hyperledger/fabric/core/chaincode/lifecycle) disabled2020-03-23 11:09:00.579 UTC [endorser] callChaincode -> INFO 032 [][0305b40d] Exit chaincode: name:"cscc"  (138ms)2020-03-23 11:09:00.579 UTC [comm.grpc.server] 1 -> INFO 033 unary call completed grpc.service=protos.Endorser grpc.method=ProcessProposal grpc.request_deadline=2020-03-23T11:12:00.376Z grpc.peer_address=172.21.0.1:33666 grpc.peer_subject="[email protected],L=San Francisco,ST=California,C=US" grpc.code=OK grpc.call_duration=138.731253ms2020-03-23 11:09:00.586 UTC [endorser] callChaincode -> INFO 034 [][4cb2aba9] Entry chaincode: name:"lscc" 2020-03-23 11:09:00.586 UTC [endorser] callChaincode -> INFO 035 [][4cb2aba9] Exit chaincode: name:"lscc"  (0ms)2020-03-23 11:09:00.587 UTC [comm.grpc.server] 1 -> INFO 036 unary call completed grpc.service=protos.Endorser grpc.method=ProcessProposal grpc.request_deadline=2020-03-23T11:12:00.586Z grpc.peer_address=172.21.0.1:33666 grpc.peer_subject="[email protected],L=San Francisco,ST=California,C=US" grpc.code=OK grpc.call_duration=763.574µs2020-03-23 11:09:00.587 UTC [endorser] callChaincode -> INFO 037 [][9ce83354] Entry chaincode: name:"lscc" 2020-03-23 11:09:00.588 UTC [lscc] executeInstall -> INFO 038 Installed Chaincode [simplecc] Version [1.0] to peer2020-03-23 11:09:00.588 UTC [endorser] callChaincode -> INFO 039 [][9ce83354] Exit chaincode: name:"lscc"  (0ms)2020-03-23 11:09:00.588 UTC [comm.grpc.server] 1 -> INFO 03a unary call completed grpc.service=protos.Endorser grpc.method=ProcessProposal grpc.request_deadline=2020-03-23T11:12:00.585Z grpc.peer_address=172.21.0.1:33666 grpc.peer_subject="[email protected],L=San Francisco,ST=California,C=US" grpc.code=OK grpc.call_duration=825.993µs2020-03-23 11:09:00.589 UTC [endorser] callChaincode -> INFO 03b [mychannel][94fc8796] Entry chaincode: name:"cscc" 2020-03-23 11:09:00.592 UTC [endorser] callChaincode -> INFO 03c [mychannel][94fc8796] Exit chaincode: name:"cscc"  (2ms)2020-03-23 11:09:00.592 UTC [comm.grpc.server] 1 -> INFO 03d unary call completed grpc.service=protos.Endorser grpc.method=ProcessProposal grpc.request_deadline=2020-03-23T11:12:00.589Z grpc.peer_address=172.21.0.1:33666 grpc.peer_subject="[email protected],L=San Francisco,ST=California,C=US" grpc.code=OK grpc.call_duration=3.371773ms2020-03-23 11:09:00.595 UTC [endorser] callChaincode -> INFO 03e [mychannel][8df4026b] Entry chaincode: name:"lscc" 2020-03-23 11:09:00.616 UTC [chaincode.platform.golang] GenerateDockerBuild -> INFO 03f building chaincode with ldflagsOpt: '-ldflags "-linkmode external -extldflags '-static'"'2020-03-23 11:09:06.579 UTC [gossip.election] beLeader -> INFO 040 1c60ef906f5fd9b80044fcdadcfa3394ce70f821469e50229dbdc26bbb0a833d : Becoming a leader2020-03-23 11:09:06.579 UTC [gossip.service] func1 -> INFO 041 Elected as a leader, starting delivery service for channel mychannel2020-03-23 11:09:06.580 UTC [deliveryClient] StartDeliverForChannel -> INFO 042 This peer will retrieve blocks from ordering service and disseminate to other peers in the organization for channel mychannel2020-03-23 11:09:06.583 UTC [deliveryClient] RequestBlocks -> INFO 043 Starting deliver with block [1] for channel mychannel2020-03-23 11:09:24.844 UTC [endorser] callChaincode -> INFO 044 [mychannel][8df4026b] Exit chaincode: name:"lscc"  (24249ms)2020-03-23 11:09:24.845 UTC [comm.grpc.server] 1 -> INFO 045 unary call completed grpc.service=protos.Endorser grpc.method=ProcessProposal grpc.request_deadline=2020-03-23T11:12:00.589Z grpc.peer_address=172.21.0.1:33666 grpc.peer_subject="[email protected],L=San Francisco,ST=California,C=US" grpc.code=OK grpc.call_duration=24.251517016s