Hyperledger Fabric Java Chaincode Timeout Expired While Starting Chaincode

I am running Hyperledger Fabric v2.2.3 in Oracle Linux 8, and trying to run Java chaincode using External Builder and Launcher method. I have no idea at which point I am doing wrong or configure wrong. By invoking the chaincode via cli, and after waiting quite some time, about 15 mins, it always giving out chaincode registration failed: timeout expired while starting chaincode. It seems to me not able to connect or reached my chaincode, but seems my suspicious is wrong, if not reaching, my chaincode log wont have any debugging info as below.

Here is my committed chaincode in my peer:

[user@hyperledgerfabric ~]# /appl/hyperledger-fabric/bin/peer lifecycle chaincode queryapproved -C orderer-channel -n TestHLF --peerAddresses localhost:7051 -o localhost:7050

Approved chaincode definition for chaincode 'TestHLF' on channel 'orderer-channel':
sequence: 1, version: 1.0.0, init-required: false, package-id: TestHLF:9081c95c231420aff76d311b14ae0eb468c199ee7aecea6e74934b588e3a3672, endorsement plugin: escc, validation plugin: vscc

[user@hyperledgerfabric ~]# /appl/hyperledger-fabric/bin/peer lifecycle chaincode querycommitted -C orderer-channel -n TestHLF --peerAddresses localhost:7051 -o localhost:7050

Committed chaincode definition for chaincode 'TestHLF' on channel 'orderer-channel':
Version: 1.0.0, Sequence: 1, Endorsement Plugin: escc, Validation Plugin: vscc, Approvals: [MyOrg1: true]

connection.json:

{
  "address": "192.168.196.1:9999",
  "dial_timeout": "10s",
  "tls_required": false,
  "client_auth_required": false
}

My Java Chaincode (running at 192.168.196.1):

@Contract(
  name = "TestHLF",
  info = @Info(
    title = "Testing Hyperledger Fabric",
    description = "Testing Hyperledger Fabric",
    version = "1.0.0",
    license = @License(
      name = "Apache 2.0 License",
      url = "http://www.apache.org/licenses/LICENSE-2.0.html"
    ),
    contact = @Contact(
      email = "test@example.com",
      name = "Test",
      url = "https://test.example.com"
    )
  )
)

@Default
public final class TestHLF implements ContractInterface {
  @Transaction()
  public void init(Context context) {
    // do nothing
  }

  @Transaction(intent = TYPE.EVALUATE)
  public void insert(Context context, String key, String val) {
    ChaincodeStub stub = context.getStub();
    stub.putStringState(key, val);
  }

  @Transaction(intent = TYPE.EVALUATE)
  public String retrieve(Context context, String key) {
    ChaincodeStub stub = context.getStub();
    String val = stub.getStringState(key);
    return val;
  }

  public static void main(String[] args) throws Exception {
    ChaincodeServerProperties props = new ChaincodeServerProperties();
    props.setPortChaincodeServer(9999);
    props.setTlsEnabled(false);

    ContractRouter router = new ContractRouter(new String[] { "-i", "TestHLF:9081c95c231420aff76d311b14ae0eb468c199ee7aecea6e74934b588e3a3672", "-a", "192.168.196.134:7052" });
    ChaincodeServer server = new NettyChaincodeServer(router, props);
    router.startRouterWithChaincodeServer(server);
  }
}

Once I started my Java chaincode, the log here printed in the console:

org.hyperledger.fabric.contract.ContractRouter startRouterWithChaincodeServer    Starting ChaincodeServer
org.hyperledger.fabric.shim.ChaincodeBase newChannelBuilder                      Configuring channel connection to peer.
org.hyperledger.fabric.shim.ChaincodeBase getMaxInboundMessageSize               Maximum Inbound Message Size [MAX_INBOUND_MESSAGE_SIZE] = 104857600
org.hyperledger.fabric.shim.impl.InvocationTaskManager <init>                    Max Pool Size [TP_MAX_POOL_SIZE]5
org.hyperledger.fabric.shim.impl.InvocationTaskManager <init>                    Queue Size [TP_CORE_POOL_SIZE]5000
org.hyperledger.fabric.shim.impl.InvocationTaskManager <init>                    Core Pool Size [TP_QUEUE_SIZE]5
org.hyperledger.fabric.shim.impl.InvocationTaskManager <init>                    Keep Alive Time [TP_KEEP_ALIVE_MS]5000
org.hyperledger.fabric.shim.impl.InvocationTaskExecutor <init>                   Thread pool created
org.hyperledger.fabric.shim.impl.InvocationTaskManager register                  Registering new chaincode name: "TestHLF:faf2e95f07eeb641dc445e5b8c1ed4d838e08110e233f86d3a157369e8ab68f4"

Invoking the chaincode via cli, and here are the debug log:

[user@hyperledgerfabric ~]# /appl/hyperledger-fabric/bin/peer chaincode query -C orderer-channel -n TestHLF -c '{"Args":["retrieve", "key1"]}' --peerAddresses localhost:7051 -o localhost:7050

[msp] setupSigningIdentity -> DEBU 01a Signing identity expires at 2041-09-03 11:18:06 +0000 UTC
[grpc] Infof -> DEBU 01b parsed scheme: ""
[grpc] Infof -> DEBU 01c scheme "" not registered, fallback to default scheme
[grpc] Infof -> DEBU 01d ccResolverWrapper: sending update to cc: {[{localhost:7051  <nil> 0 <nil>}] <nil> <nil>}
[grpc] Infof -> DEBU 01e ClientConn switching balancer to "pick_first"
[grpc] Infof -> DEBU 01f Channel switches to new LB policy "pick_first"
[grpc] Infof -> DEBU 020 Subchannel Connectivity change to CONNECTING
[grpc] Infof -> DEBU 021 Subchannel picks a new address "localhost:7051" to connect
[grpc] UpdateSubConnState -> DEBU 022 pickfirstBalancer: HandleSubConnStateChange: 0xc00062f180, {CONNECTING <nil>}
[grpc] Infof -> DEBU 023 Channel Connectivity change to CONNECTING
[grpc] Infof -> DEBU 024 Subchannel Connectivity change to READY
[grpc] UpdateSubConnState -> DEBU 025 pickfirstBalancer: HandleSubConnStateChange: 0xc00062f180, {READY <nil>}
[grpc] Infof -> DEBU 026 Channel Connectivity change to READY
[grpc] Infof -> DEBU 027 parsed scheme: ""
[grpc] Infof -> DEBU 028 scheme "" not registered, fallback to default scheme
[grpc] Infof -> DEBU 029 ccResolverWrapper: sending update to cc: {[{localhost:7051  <nil> 0 <nil>}] <nil> <nil>}
[grpc] Infof -> DEBU 02a ClientConn switching balancer to "pick_first"
[grpc] Infof -> DEBU 02b Channel switches to new LB policy "pick_first"
[grpc] Infof -> DEBU 02c Subchannel Connectivity change to CONNECTING
[grpc] Infof -> DEBU 02d Subchannel picks a new address "localhost:7051" to connect
[grpc] UpdateSubConnState -> DEBU 02e pickfirstBalancer: HandleSubConnStateChange: 0xc000487740, {CONNECTING <nil>}
[grpc] Infof -> DEBU 02f Channel Connectivity change to CONNECTING
[grpc] Infof -> DEBU 030 Subchannel Connectivity change to READY
[grpc] UpdateSubConnState -> DEBU 031 pickfirstBalancer: HandleSubConnStateChange: 0xc000487740, {READY <nil>}
[grpc] Infof -> DEBU 032 Channel Connectivity change to READY
[msp] GetDefaultSigningIdentity -> DEBU 033 Obtaining default signing identity
[msp.identity] Sign -> DEBU 034 Sign: plaintext: 0ADA080A7008031A0C089D8DE7890610...0A0872657472696576650A046B657931
[msp.identity] Sign -> DEBU 035 Sign: digest: 4547C3BCC4282800F22B492EAEACA349210131015A22084C726B14F6B1740B26
Error: endorsement failure during query. response: status:500 message:"error in simulation: failed to execute transaction 6beee4b1394198e8b2d7890c96d880f3aabbf3782932492ff3a0af3a5336fd50: could not launch chaincode TestHLF:9081c95c231420aff76d311b14ae0eb468c199ee7aecea6e74934b588e3a3672: chaincode registration failed: timeout expired while starting chaincode TestHLF:9081c95c231420aff76d311b14ae0eb468c199ee7aecea6e74934b588e3a3672 for transaction"

The debug log due to not able to post here (body size limit and “this looks like spam”),

Debug log for Peer after during startup and executing the chaincode: https://github.com/SawJK/fabric-temp/blob/main/fabric-peer-log-0001

Debug log for Java chaincode using log4j2: https://github.com/SawJK/fabric-temp/blob/main/fabric-java-chaincode-log-0001

Answer

I miss the CCID of the chaincode. Not really sure about Java API (I’m more into Go API), but it should be specified somewhere. You can try with…

    ContractRouter router = new ContractRouter(new String[] { "-i", "TestHLF:9081c95c231420aff76d311b14ae0eb468c199ee7aecea6e74934b588e3a3672", "-a", "192.168.196.134:7052" });

…although I think it expects simply “TestHLF”. It does not seem to be documented for Java… https://hyperledger-fabric.readthedocs.io/en/release-2.2/cc_service.html#writing-chaincode-to-run-as-an-external-service

I’ve taken the CCID directly from your peer’s error logs.