<p>I'm running a network in a Kubernetes Cluster and have a CLI, a Peer and an Orderer of the same organization each running in it's own Pod.
I can do channel creation, chaincode installation, approvement and committing without problems. However, when it comes to chaincode invocation, the CLI outputs that the chaincode might not be installed, while the Peer logs a failed connection to the CLI.</p>
<p>So here's the CLI command (<strong>update:</strong> with <code>-o org1-orderer:30011</code>):</p>
<pre class="lang-sh prettyprint-override"><code>$ export CORE_PEER_MSPCONFIGPATH=/config/admin/msp
$ peer chaincode invoke -C channel1 -n cc-abac -c '{&quot;Args&quot;:[&quot;invoke&quot;,&quot;a&quot;,&quot;b&quot;,&quot;10&quot;]}' -o org1-orderer:30011 --clientauth --tls --cafile /config/peer/tls-msp/tlscacerts/ca-cert.pem --keyfile /config/peer/tls-msp/keystore/key.pem --certfile /config/peer/tls-msp/signcerts
/cert.pem
</code></pre>
<p>CLI Output:</p>
<pre><code>2020-07-07 16:47:20.918 UTC [msp] loadCertificateAt -&gt; WARN 001 Failed loading ClientOU certificate at [/config/admin/msp]: [could not read file /config/admin/msp: read /config/admin/msp: is a directory]
2020-07-07 16:47:20.919 UTC [msp] loadCertificateAt -&gt; WARN 002 Failed loading PeerOU certificate at [/config/admin/msp]: [could not read file /config/admin/msp: read /config/admin/msp: is a directory]
2020-07-07 16:47:20.919 UTC [msp] loadCertificateAt -&gt; WARN 003 Failed loading AdminOU certificate at [/config/admin/msp]: [could not read file /config/admin/msp: read /config/admin/msp: is a directory]
2020-07-07 16:47:20.919 UTC [msp] loadCertificateAt -&gt; WARN 004 Failed loading OrdererOU certificate at [/config/admin/msp]: [could not read file /config/admin/msp: read /config/admin/msp: is a directory]
2020-07-07 16:47:20.928 UTC [grpc] Infof -&gt; DEBU 005 parsed scheme: &quot;&quot;
2020-07-07 16:47:20.928 UTC [grpc] Infof -&gt; DEBU 006 scheme &quot;&quot; not registered, fallback to default scheme
2020-07-07 16:47:20.928 UTC [grpc] Infof -&gt; DEBU 007 ccResolverWrapper: sending update to cc: {[{org1-peer1:30151  &lt;nil&gt; 0 &lt;nil&gt;}] &lt;nil&gt; &lt;nil&gt;}
2020-07-07 16:47:20.928 UTC [grpc] Infof -&gt; DEBU 008 ClientConn switching balancer to &quot;pick_first&quot;
2020-07-07 16:47:20.928 UTC [grpc] Infof -&gt; DEBU 009 Channel switches to new LB policy &quot;pick_first&quot;
2020-07-07 16:47:20.928 UTC [grpc] Infof -&gt; DEBU 00a Subchannel Connectivity change to CONNECTING
2020-07-07 16:47:20.928 UTC [grpc] Infof -&gt; DEBU 00b Subchannel picks a new address &quot;org1-peer1:30151&quot; to connect
2020-07-07 16:47:20.928 UTC [grpc] UpdateSubConnState -&gt; DEBU 00c pickfirstBalancer: HandleSubConnStateChange: 0xc000114450, {CONNECTING &lt;nil&gt;}
2020-07-07 16:47:20.928 UTC [grpc] Infof -&gt; DEBU 00d Channel Connectivity change to CONNECTING
2020-07-07 16:47:20.935 UTC [grpc] Infof -&gt; DEBU 00e Subchannel Connectivity change to READY
2020-07-07 16:47:20.935 UTC [grpc] UpdateSubConnState -&gt; DEBU 00f pickfirstBalancer: HandleSubConnStateChange: 0xc000114450, {READY &lt;nil&gt;}
2020-07-07 16:47:20.935 UTC [grpc] Infof -&gt; DEBU 010 Channel Connectivity change to READY
2020-07-07 16:47:20.948 UTC [grpc] Infof -&gt; DEBU 011 parsed scheme: &quot;&quot;
2020-07-07 16:47:20.948 UTC [grpc] Infof -&gt; DEBU 012 scheme &quot;&quot; not registered, fallback to default scheme
2020-07-07 16:47:20.948 UTC [grpc] Infof -&gt; DEBU 013 ccResolverWrapper: sending update to cc: {[{org1-peer1:30151  &lt;nil&gt; 0 &lt;nil&gt;}] &lt;nil&gt; &lt;nil&gt;}
2020-07-07 16:47:20.948 UTC [grpc] Infof -&gt; DEBU 014 ClientConn switching balancer to &quot;pick_first&quot;
2020-07-07 16:47:20.948 UTC [grpc] Infof -&gt; DEBU 015 Channel switches to new LB policy &quot;pick_first&quot;
2020-07-07 16:47:20.948 UTC [grpc] Infof -&gt; DEBU 016 Subchannel Connectivity change to CONNECTING
2020-07-07 16:47:20.948 UTC [grpc] Infof -&gt; DEBU 017 Subchannel picks a new address &quot;org1-peer1:30151&quot; to connect
2020-07-07 16:47:20.948 UTC [grpc] UpdateSubConnState -&gt; DEBU 018 pickfirstBalancer: HandleSubConnStateChange: 0xc000496070, {CONNECTING &lt;nil&gt;}
2020-07-07 16:47:20.948 UTC [grpc] Infof -&gt; DEBU 019 Channel Connectivity change to CONNECTING
2020-07-07 16:47:20.954 UTC [grpc] Infof -&gt; DEBU 01a Subchannel Connectivity change to READY
2020-07-07 16:47:20.955 UTC [grpc] UpdateSubConnState -&gt; DEBU 01b pickfirstBalancer: HandleSubConnStateChange: 0xc000496070, {READY &lt;nil&gt;}
2020-07-07 16:47:20.955 UTC [grpc] Infof -&gt; DEBU 01c Channel Connectivity change to READY
2020-07-07 16:47:20.987 UTC [chaincodeCmd] InitCmdFactory -&gt; INFO 01d Retrieved channel (channel1) orderer endpoint: org1-orderer:30011
2020-07-07 16:47:20.991 UTC [grpc] WithKeepaliveParams -&gt; DEBU 01e Adjusting keepalive ping interval to minimum period of 10s
2020-07-07 16:47:20.991 UTC [grpc] Infof -&gt; DEBU 01f parsed scheme: &quot;&quot;
2020-07-07 16:47:20.991 UTC [grpc] Infof -&gt; DEBU 020 scheme &quot;&quot; not registered, fallback to default scheme
2020-07-07 16:47:20.991 UTC [grpc] Infof -&gt; DEBU 021 ccResolverWrapper: sending update to cc: {[{org1-orderer:30011  &lt;nil&gt; 0 &lt;nil&gt;}] &lt;nil&gt; &lt;nil&gt;}
2020-07-07 16:47:20.991 UTC [grpc] Infof -&gt; DEBU 022 ClientConn switching balancer to &quot;pick_first&quot;
2020-07-07 16:47:20.991 UTC [grpc] Infof -&gt; DEBU 023 Channel switches to new LB policy &quot;pick_first&quot;
2020-07-07 16:47:20.991 UTC [grpc] Infof -&gt; DEBU 024 Subchannel Connectivity change to CONNECTING
2020-07-07 16:47:20.991 UTC [grpc] Infof -&gt; DEBU 025 Subchannel picks a new address &quot;org1-orderer:30011&quot; to connect
2020-07-07 16:47:20.991 UTC [grpc] UpdateSubConnState -&gt; DEBU 026 pickfirstBalancer: HandleSubConnStateChange: 0xc000205a60, {CONNECTING &lt;nil&gt;}
2020-07-07 16:47:20.991 UTC [grpc] Infof -&gt; DEBU 027 Channel Connectivity change to CONNECTING
2020-07-07 16:47:21.000 UTC [grpc] Infof -&gt; DEBU 028 Subchannel Connectivity change to READY
2020-07-07 16:47:21.000 UTC [grpc] UpdateSubConnState -&gt; DEBU 029 pickfirstBalancer: HandleSubConnStateChange: 0xc000205a60, {READY &lt;nil&gt;}
2020-07-07 16:47:21.000 UTC [grpc] Infof -&gt; DEBU 02a Channel Connectivity change to READY
Error: endorsement failure during invoke. response: status:500 message:&quot;make sure the chaincode cc-abac has been successfully defined on channel channel1 and try again: chaincode definition for 'cc-abac' exists, but chaincode is not installed&quot;
</code></pre>
<p>I'm sure it's installed on channel1 (the only channel in existence, except sys-channel):</p>
<pre><code>$ peer lifecycle chaincode queryinstalled
Installed chaincodes on peer:
Package ID: cc-abac:4992a37bf5c7b48f91f5062d9700a58a4129599c53d759e8282fdeffc8836c72, Label: cc-abac
</code></pre>
<p>On the Peer's side, I get the following in the log (<strong>updated</strong>):</p>
<pre><code>[36m2020-07-09 06:45:55.976 UTC [gossip.discovery] periodicalSendAlive -&gt; DEBU 194c[0m Sleeping 5s
[36m2020-07-09 06:45:56.182 UTC [endorser] ProcessProposal -&gt; DEBU 194d[0m request from 10.129.1.229:60184
[36m2020-07-09 06:45:56.182 UTC [endorser] Validate -&gt; DEBU 194e[0m creator is valid channel=channel1 txID=a71312e4 mspID=Org1MSP
[36m2020-07-09 06:45:56.182 UTC [msp.identity] Verify -&gt; DEBU 194f[0m Verify: digest = 00000000  87 29 a0 e5 96 b8 5f 5e  9b e0 fb e5 4d 5b 86 b2  |.)...._^....M[..|
00000010  bd 43 ee 30 59 d6 a9 55  e3 e9 77 7b fd a2 47 8f  |.C.0Y..U..w{..G.|
[36m2020-07-09 06:45:56.182 UTC [msp.identity] Verify -&gt; DEBU 1950[0m Verify: sig = 00000000  30 45 02 21 00 f0 6b 23  9d f6 ec f2 29 be 64 4e  |0E.!..k#....).dN|
00000010  75 69 a7 05 7e 05 71 51  64 6c 52 59 83 be ea f9  |ui..~.qQdlRY....|
00000020  08 5e 07 09 f3 02 20 7a  f7 b0 6c e0 bb 32 b9 0c  |.^.... z..l..2..|
00000030  8c 41 be b8 ea 39 33 91  92 0b 08 9e c6 14 39 e8  |.A...93.......9.|
00000040  46 eb a5 80 7a 7d d1                              |F...z}.|
[36m2020-07-09 06:45:56.182 UTC [endorser] Validate -&gt; DEBU 1951[0m signature is valid channel=channel1 txID=a71312e4 mspID=Org1MSP
[36m2020-07-09 06:45:56.182 UTC [fsblkstorage] retrieveTransactionByID -&gt; DEBU 1952[0m retrieveTransactionByID() - txId = [a71312e411a6b417a541112e2aeac73adc8d6f7fbbb3c62ffcad2348e0c91fac]
[36m2020-07-09 06:45:56.182 UTC [leveldbhelper] GetIterator -&gt; DEBU 1953[0m Getting iterator for range [[]byte{0x63, 0x68, 0x61, 0x6e, 0x6e, 0x65, 0x6c, 0x31, 0x0, 0x74, 0x1, 0x40, 0x61, 0x37, 0x31, 0x33, 0x31, 0x32, 0x65, 0x34, 0x31, 0x31, 0x61, 0x36, 0x62, 0x34, 0x31, 0x37, 0x61, 0x35, 0x34, 0x31, 0x31, 0x31, 0x32, 0x65, 0x32, 0x61, 0x65, 0x61, 0x63, 0x37, 0x33, 0x61, 0x64, 0x63, 0x38, 0x64, 0x36, 0x66, 0x37, 0x66, 0x62, 0x62, 0x62, 0x33, 0x63, 0x36, 0x32, 0x66, 0x66, 0x63, 0x61, 0x64, 0x32, 0x33, 0x34, 0x38, 0x65, 0x30, 0x63, 0x39, 0x31, 0x66, 0x61, 0x63}] - [[]byte{0x63, 0x68, 0x61, 0x6e, 0x6e, 0x65, 0x6c, 0x31, 0x0, 0x74, 0x1, 0x40, 0x61, 0x37, 0x31, 0x33, 0x31, 0x32, 0x65, 0x34, 0x31, 0x31, 0x61, 0x36, 0x62, 0x34, 0x31, 0x37, 0x61, 0x35, 0x34, 0x31, 0x31, 0x31, 0x32, 0x65, 0x32, 0x61, 0x65, 0x61, 0x63, 0x37, 0x33, 0x61, 0x64, 0x63, 0x38, 0x64, 0x36, 0x66, 0x37, 0x66, 0x62, 0x62, 0x62, 0x33, 0x63, 0x36, 0x32, 0x66, 0x66, 0x63, 0x61, 0x64, 0x32, 0x33, 0x34, 0x38, 0x65, 0x30, 0x63, 0x39, 0x31, 0x66, 0x61, 0x63, 0xff}]
[36m2020-07-09 06:45:56.182 UTC [aclmgmt] CheckACL -&gt; DEBU 1954[0m acl policy /Channel/Application/Writers found in config for resource peer/Propose
[36m2020-07-09 06:45:56.182 UTC [aclmgmt] CheckACL -&gt; DEBU 1955[0m acl check(/Channel/Application/Writers)
[36m2020-07-09 06:45:56.183 UTC [policies] EvaluateSignedData -&gt; DEBU 1956[0m == Evaluating *policies.ImplicitMetaPolicy Policy /Channel/Application/Writers ==
[36m2020-07-09 06:45:56.183 UTC [policies] EvaluateSignedData -&gt; DEBU 1957[0m This is an implicit meta policy, it will trigger other policy evaluations, whose failures may be benign
[36m2020-07-09 06:45:56.183 UTC [policies] EvaluateSignedData -&gt; DEBU 1958[0m == Evaluating *cauthdsl.policy Policy /Channel/Application/Org1/Writers ==
[36m2020-07-09 06:45:56.183 UTC [msp.identity] Verify -&gt; DEBU 1959[0m Verify: digest = 00000000  87 29 a0 e5 96 b8 5f 5e  9b e0 fb e5 4d 5b 86 b2  |.)...._^....M[..|
00000010  bd 43 ee 30 59 d6 a9 55  e3 e9 77 7b fd a2 47 8f  |.C.0Y..U..w{..G.|
[36m2020-07-09 06:45:56.183 UTC [msp.identity] Verify -&gt; DEBU 195a[0m Verify: sig = 00000000  30 45 02 21 00 f0 6b 23  9d f6 ec f2 29 be 64 4e  |0E.!..k#....).dN|
00000010  75 69 a7 05 7e 05 71 51  64 6c 52 59 83 be ea f9  |ui..~.qQdlRY....|
00000020  08 5e 07 09 f3 02 20 7a  f7 b0 6c e0 bb 32 b9 0c  |.^.... z..l..2..|
00000030  8c 41 be b8 ea 39 33 91  92 0b 08 9e c6 14 39 e8  |.A...93.......9.|
00000040  46 eb a5 80 7a 7d d1                              |F...z}.|
[36m2020-07-09 06:45:56.183 UTC [policies] SignatureSetToValidIdentities -&gt; DEBU 195b[0m signature for identity 0 validated
[36m2020-07-09 06:45:56.183 UTC [cauthdsl] func1 -&gt; DEBU 195c[0m 0xc0006210e0 gate 1594277156183221199 evaluation starts
[36m2020-07-09 06:45:56.183 UTC [cauthdsl] func2 -&gt; DEBU 195d[0m 0xc0006210e0 signed by 0 principal evaluation starts (used [false])
[36m2020-07-09 06:45:56.183 UTC [cauthdsl] func2 -&gt; DEBU 195e[0m 0xc0006210e0 processing identity 0 - &amp;{Org1MSP 0b33fd619da73c0915b76088b0678047f834593ea6a4f22f0772b36f3c6bd68f}
[36m2020-07-09 06:45:56.183 UTC [cauthdsl] func2 -&gt; DEBU 195f[0m 0xc0006210e0 principal evaluation succeeds for identity 0
[36m2020-07-09 06:45:56.183 UTC [cauthdsl] func1 -&gt; DEBU 1960[0m 0xc0006210e0 gate 1594277156183221199 evaluation succeeds
[36m2020-07-09 06:45:56.183 UTC [policies] EvaluateSignedData -&gt; DEBU 1961[0m Signature set satisfies policy /Channel/Application/Org1/Writers
[36m2020-07-09 06:45:56.183 UTC [policies] EvaluateSignedData -&gt; DEBU 1962[0m == Done Evaluating *cauthdsl.policy Policy /Channel/Application/Org1/Writers
[36m2020-07-09 06:45:56.183 UTC [policies] EvaluateSignedData -&gt; DEBU 1963[0m Signature set satisfies policy /Channel/Application/Writers
[36m2020-07-09 06:45:56.183 UTC [policies] EvaluateSignedData -&gt; DEBU 1964[0m == Done Evaluating *policies.ImplicitMetaPolicy Policy /Channel/Application/Writers
[36m2020-07-09 06:45:56.183 UTC [lockbasedtxmgr] NewTxSimulator -&gt; DEBU 1965[0m constructing new tx simulator
[36m2020-07-09 06:45:56.183 UTC [lockbasedtxmgr] newLockBasedTxSimulator -&gt; DEBU 1966[0m constructing new tx simulator txid = [a71312e411a6b417a541112e2aeac73adc8d6f7fbbb3c62ffcad2348e0c91fac]
[36m2020-07-09 06:45:56.183 UTC [stateleveldb] GetState -&gt; DEBU 1967[0m GetState(). ns=_lifecycle, key=namespaces/fields/cc-abac/Sequence
[36m2020-07-09 06:45:56.183 UTC [lockbasedtxmgr] Done -&gt; DEBU 1968[0m Done with transaction simulation / query execution [a71312e411a6b417a541112e2aeac73adc8d6f7fbbb3c62ffcad2348e0c91fac]
[34m2020-07-09 06:45:56.183 UTC [comm.grpc.server] 1 -&gt; INFO 1969[0m unary call completed grpc.service=protos.Endorser grpc.method=ProcessProposal grpc.peer_address=10.129.1.229:60184 grpc.peer_subject=&quot;CN=org1-peer1,OU=peer,O=Hyperledger,ST=North Carolina,C=US&quot; grpc.code=OK grpc.call_duration=1.225382ms
[36m2020-07-09 06:45:56.186 UTC [grpc] warningf -&gt; DEBU 196a[0m transport: http2Server.HandleStreams failed to read frame: read tcp 10.130.2.65:7051-&gt;10.129.1.229:60184: read: connection reset by peer
[36m2020-07-09 06:45:56.186 UTC [grpc] infof -&gt; DEBU 196b[0m transport: loopyWriter.run returning. connection error: desc = &quot;transport is closing&quot;
[36m2020-07-09 06:45:56.186 UTC [grpc] infof -&gt; DEBU 196c[0m transport: loopyWriter.run returning. connection error: desc = &quot;transport is closing&quot;
</code></pre>
<p><strong>[update]</strong> The message <code>unary call completed grpc.service=protos.Endorser grpc.method=ProcessProposal grpc.peer_address=10.129.1.229:60184 grpc.peer_subject=&quot;CN=org1-peer1,OU=peer,O=Hyperledger,ST=North Carolina,C=US&quot; grpc.code=OK grpc.call_duration=1.225382ms</code> indicates that the Peer considers the CLI as another Peer, doesn't it? If so, it's clear why the connection is failing. Now the question is, why the Peer thinks so?</p>
<p>Peer: 10.130.2.65<br />
CLI: 10.129.1.229</p>
<p>Kind regards</p>

haggis
<p>Unfortunately, all of the GRPC logs and k8s related issues appear to be a red herring.  The connection is being correctly established, the term 'peer' is simply a little confusing in the GRPC logs, as GRPC always refers to 'the party on the other end of the line' as a 'peer'.  This term is re-used with a different meaning in Fabric.</p>
<p>As the logs indicate, the chaincode has been successfully approved, and defined on the channel.</p>
<p>As the peer CLI output indicates, you have installed a chaincode with package-id <code>cc-abac:4992a37bf5c7b48f91f5062d9700a58a4129599c53d759e8282fdeffc8836c72</code>.</p>
<p>But, on invoke, you are seeing the error that:</p>
<p><code>chaincode definition for 'cc-abac' exists, but chaincode is not installed</code></p>
<p>This means when you did your chaincode approval, you either did not specify a package-id, or, you specified an incorrect package id.</p>
<p>If you are using a v2.2+ version of Fabric, you should be able to use the <code>peer lifecycle queryapproved</code> utility to see what package ID you have selected.</p>
<p>You can re-run the <code>peer lifecycle approveformyorg</code> with the correct package-id (<code>cc-abac:4992a37bf5c7b48f91f5062d9700a58a4129599c53d759e8282fdeffc8836c72</code>) and this should correct things.</p>
