Hyperledger Fabric Invoke Java Chaincode(as a external service) timeout

Question

I am trying to implement chaincode as external service by Java with Fabric 2.2.3. The invoke of contract method from peer always be timeout.

My peers and network should be fine because it works fine when I run a contract service with GO in the same environment. I have no idea at which point I am doing wrong or configure wrong.

My Contract MyAssetContract.java:

@Slf4j
@Contract(name = "myAssetContract", info = @Info(title = "MyAssetContract contract", description = "My Smart Contract", version = "0.0.1", license = @License(name = "Apache-2.0", url = "")))
@Default
public class MyAssetContract implements ContractInterface {

    public MyAssetContract() {
    }

    @Transaction()
    public boolean myAssetExists(Context ctx, String myAssetId) {
        log.info("myAssetExists: {}", myAssetId);
        byte[] buffer = ctx.getStub().getState(myAssetId);
        return (buffer != null && buffer.length > 0);
    }

    // other contract methods...

}

The MyAsset.java:

@DataType()
public class MyAsset {

    @Property()
    private String value;

    public MyAsset() {
    }

    public String getValue() {
        return value;
    }

    public void setValue(String value) {
        this.value = value;
    }
}

I start the service like this:

try {
      ChaincodeServerProperties chaincodeServerProperties = new ChaincodeServerProperties();

      final int port = properties.getPort(); // get from SpringBoot configuration
      final String coreChaincodeIdName = properties.getCcid();  // get from SpringBoot configuration

      chaincodeServerProperties.setPortChaincodeServer(port);
      chaincodeServerProperties.setMaxConnectionAgeSeconds(Integer.MAX_VALUE);
      ContractRouter contractRouter = new ContractRouter(new String[] { "-i", coreChaincodeIdName });
      ChaincodeServer chaincodeServer = new NettyChaincodeServer(contractRouter, chaincodeServerProperties);
      contractRouter.startRouterWithChaincodeServer(chaincodeServer);
  } catch (Throwable e) {
      throw new RuntimeException("start ChaincodeServer failed", e);
}

Contract Service Start log:

(ignore Spring logs ...)

2021-10-18 16:58:02.362 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-429 - <<<<<<<<<<<<<Environment options>>>>>>>>>>>>
2021-10-18 16:58:02.363 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-430 - CORE_CHAINCODE_ID_NAME: null
2021-10-18 16:58:02.363 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-431 - CORE_PEER_ADDRESS: 127.0.0.1
2021-10-18 16:58:02.363 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-432 - CORE_PEER_TLS_ENABLED: false
2021-10-18 16:58:02.364 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-433 - CORE_PEER_TLS_ROOTCERT_FILE: null
2021-10-18 16:58:02.364 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-434 - CORE_TLS_CLIENT_KEY_PATH: null
2021-10-18 16:58:02.364 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-435 - CORE_TLS_CLIENT_CERT_PATH: null
2021-10-18 16:58:02.364 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-436 - CORE_PEER_LOCALMSPID: 
2021-10-18 16:58:02.364 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-437 - LOGLEVEL: null
2021-10-18 16:58:02.370 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-388 - <<<<<<<<<<<<<CommandLine options>>>>>>>>>>>>
2021-10-18 16:58:02.370 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-389 - CORE_CHAINCODE_ID_NAME: myAssetContract:bb0caa4c55ad6d7d3e58244b436c3858ed9d9726c4efccc0e75852d5523f0042
2021-10-18 16:58:02.370 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-390 - CORE_PEER_ADDRESS: 127.0.0.1:7051
2021-10-18 16:58:02.371 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-391 - CORE_PEER_TLS_ENABLED: false
2021-10-18 16:58:02.371 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-392 - CORE_PEER_TLS_ROOTCERT_FILE: null
2021-10-18 16:58:02.371 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-393 - CORE_TLS_CLIENT_KEY_PATH: null
2021-10-18 16:58:02.371 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-394 - CORE_TLS_CLIENT_CERT_PATH: null
2021-10-18 16:58:02.372 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-467 - <<<<<<<<<<<<<Properties options>>>>>>>>>>>>
2021-10-18 16:58:02.373 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-468 - {CORE_CHAINCODE_ID_NAME=myAssetContract:bb0caa4c55ad6d7d3e58244b436c3858ed9d9726c4efccc0e75852d5523f0042, CORE_PEER_ADDRESS=127.0.0.1}
2021-10-18 16:58:02.375 [INFO ] [] - org.hyperledger.fabric.metrics.Metrics-62 - Metrics disabled
2021-10-18 16:58:03.388 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.logging.InternalLoggerFactory-45 - Using SLF4J as the default logging framework
2021-10-18 16:58:03.390 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent-1003 - Platform: Windows
2021-10-18 16:58:03.395 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent0-396 - -Dio.netty.noUnsafe: false
2021-10-18 16:58:03.395 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent0-852 - Java version: 8
2021-10-18 16:58:03.397 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent0-121 - sun.misc.Unsafe.theUnsafe: available
2021-10-18 16:58:03.398 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent0-145 - sun.misc.Unsafe.copyMemory: available
2021-10-18 16:58:03.399 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent0-183 - java.nio.Buffer.address: available
2021-10-18 16:58:03.400 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent0-244 - direct buffer constructor: available
2021-10-18 16:58:03.401 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent0-314 - java.nio.Bits.unaligned: available, true
2021-10-18 16:58:03.402 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent0-379 - jdk.internal.misc.Unsafe.allocateUninitializedArray(int): unavailable prior to Java9
2021-10-18 16:58:03.402 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent0-386 - java.nio.DirectByteBuffer.<init>(long, int): available
2021-10-18 16:58:03.402 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent-1046 - sun.misc.Unsafe: available
2021-10-18 16:58:03.405 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent-1165 - -Dio.netty.tmpdir: C:\Users\alice\AppData\Local\Temp (java.io.tmpdir)
2021-10-18 16:58:03.405 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent-1244 - -Dio.netty.bitMode: 64 (sun.arch.data.model)
2021-10-18 16:58:03.406 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent-177 - -Dio.netty.maxDirectMemory: 3741319168 bytes
2021-10-18 16:58:03.407 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent-184 - -Dio.netty.uninitializedArrayAllocationThreshold: -1
2021-10-18 16:58:03.408 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.CleanerJava6-92 - java.nio.ByteBuffer.cleaner(): available
2021-10-18 16:58:03.408 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent-204 - -Dio.netty.noPreferDirect: false
2021-10-18 16:58:03.468 [INFO ] [] - org.hyperledger.fabric.shim.NettyGrpcServer-85 - <<<<<<<<<<<<<chaincodeServerProperties>>>>>>>>>>>>:

2021-10-18 16:58:03.468 [INFO ] [] - org.hyperledger.fabric.shim.NettyGrpcServer-86 - PortChaincodeServer:23456
2021-10-18 16:58:03.468 [INFO ] [] - org.hyperledger.fabric.shim.NettyGrpcServer-87 - MaxInboundMetadataSize:104857600
2021-10-18 16:58:03.468 [INFO ] [] - org.hyperledger.fabric.shim.NettyGrpcServer-88 - MaxInboundMessageSize:104857600
2021-10-18 16:58:03.469 [INFO ] [] - org.hyperledger.fabric.shim.NettyGrpcServer-89 - MaxConnectionAgeSeconds:2147483647
2021-10-18 16:58:03.469 [INFO ] [] - org.hyperledger.fabric.shim.NettyGrpcServer-90 - KeepAliveTimeoutSeconds:20
2021-10-18 16:58:03.469 [INFO ] [] - org.hyperledger.fabric.shim.NettyGrpcServer-91 - PermitKeepAliveTimeMinutes:1
2021-10-18 16:58:03.469 [INFO ] [] - org.hyperledger.fabric.shim.NettyGrpcServer-92 - KeepAliveTimeMinutes:1
2021-10-18 16:58:03.469 [INFO ] [] - org.hyperledger.fabric.shim.NettyGrpcServer-93 - PermitKeepAliveWithoutCalls:true
2021-10-18 16:58:03.469 [INFO ] [] - org.hyperledger.fabric.shim.NettyGrpcServer-94 - KeyPassword:null
2021-10-18 16:58:03.469 [INFO ] [] - org.hyperledger.fabric.shim.NettyGrpcServer-95 - KeyCertChainFile:null
2021-10-18 16:58:03.470 [INFO ] [] - org.hyperledger.fabric.shim.NettyGrpcServer-96 - KeyFile:null
2021-10-18 16:58:03.470 [INFO ] [] - org.hyperledger.fabric.shim.NettyGrpcServer-97 - isTlsEnabled:false
2021-10-18 16:58:03.470 [INFO ] [] - org.hyperledger.fabric.shim.NettyGrpcServer-98 - 

2021-10-18 16:58:03.490 [DEBUG] [] - io.grpc.netty.shaded.io.netty.channel.MultithreadEventLoopGroup-44 - -Dio.netty.eventLoopThreads: 16
2021-10-18 16:58:03.510 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.InternalThreadLocalMap-56 - -Dio.netty.threadLocalMap.stringBuilder.initialSize: 1024
2021-10-18 16:58:03.511 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.InternalThreadLocalMap-59 - -Dio.netty.threadLocalMap.stringBuilder.maxSize: 4096
2021-10-18 16:58:03.523 [DEBUG] [] - io.grpc.netty.shaded.io.netty.channel.nio.NioEventLoop-106 - -Dio.netty.noKeySetOptimization: false
2021-10-18 16:58:03.523 [DEBUG] [] - io.grpc.netty.shaded.io.netty.channel.nio.NioEventLoop-107 - -Dio.netty.selectorAutoRebuildThreshold: 512
2021-10-18 16:58:03.540 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.internal.PlatformDependent-907 - org.jctools-core.MpscChunkedArrayQueue: available
2021-10-18 16:58:05.119 [INFO ] [] - org.hyperledger.fabric.contract.routing.impl.ContractDefinitionImpl-70 - Found class: com.example.contract.MyAssetContract
2021-10-18 16:58:05.124 [INFO ] [] - org.hyperledger.fabric.contract.routing.impl.ContractDefinitionImpl-70 - Found class: org.hyperledger.fabric.contract.systemcontract.SystemContract
2021-10-18 16:58:05.129 [INFO ] [] - org.hyperledger.fabric.contract.metadata.MetadataBuilder-56 - email 
2021-10-18 16:58:05.130 [INFO ] [] - org.hyperledger.fabric.contract.metadata.MetadataBuilder-56 - name 
2021-10-18 16:58:05.130 [INFO ] [] - org.hyperledger.fabric.contract.metadata.MetadataBuilder-56 - url 
2021-10-18 16:58:05.130 [INFO ] [] - org.hyperledger.fabric.contract.metadata.MetadataBuilder-56 - url 
2021-10-18 16:58:05.131 [INFO ] [] - org.hyperledger.fabric.contract.metadata.MetadataBuilder-56 - email 
2021-10-18 16:58:05.131 [INFO ] [] - org.hyperledger.fabric.contract.metadata.MetadataBuilder-56 - name 
2021-10-18 16:58:05.132 [INFO ] [] - org.hyperledger.fabric.contract.metadata.MetadataBuilder-56 - url 
2021-10-18 16:58:05.132 [INFO ] [] - org.hyperledger.fabric.contract.metadata.MetadataBuilder-56 - url 
2021-10-18 16:58:05.132 [INFO ] [] - org.hyperledger.fabric.contract.metadata.MetadataBuilder-56 - email 
2021-10-18 16:58:05.132 [INFO ] [] - org.hyperledger.fabric.contract.metadata.MetadataBuilder-56 - name 
2021-10-18 16:58:05.132 [INFO ] [] - org.hyperledger.fabric.contract.metadata.MetadataBuilder-56 - url 
2021-10-18 16:58:05.132 [INFO ] [] - org.hyperledger.fabric.contract.metadata.MetadataBuilder-56 - url 
2021-10-18 16:58:05.135 [INFO ] [] - org.hyperledger.fabric.contract.metadata.MetadataBuilder-118 - Validating schema created
2021-10-18 16:58:05.135 [INFO ] [] - org.hyperledger.fabric.contract.metadata.MetadataBuilder-80 - Running schema test validation
2021-10-18 16:58:05.265 [INFO ] [] - org.hyperledger.fabric.contract.ContractRouter-196 - Metadata follows:{
   "components": {"schemas": {"MyAsset": {
      "additionalProperties": false,
      "type": "object",
      "properties": {"value": {"type": "string"}},
      "$id": "com.example.contract.MyAsset"
   }}},
   "$schema": "https://fabric-shim.github.io/release-1.4/contract-schema.json",
   "contracts": {
      "myAssetContract": {
         "name": "myAssetContract",
         "transactions": [
            {
               "name": "myAssetExists",
               "returns": {"type": "boolean"},
               "parameters": [{
                  "schema": {"type": "string"},
                  "name": "arg1"
               }],
               "tags": [
                  "SUBMIT",
                  "INVOKE"
               ]
            }
         ],
         "info": {
            "license": {"name": "Apache-2.0"},
            "description": "My Smart Contract",
            "termsOfService": "",
            "title": "MyAssetContract contract",
            "version": "0.0.1",
            "contact": {}
         }
      },
      "org.hyperledger.fabric": {
         "name": "org.hyperledger.fabric",
         "transactions": [{
            "name": "GetMetadata",
            "returns": {"type": "string"},
            "parameters": [],
            "tags": [
               "SUBMIT",
               "INVOKE"
            ]
         }],
         "info": {
            "license": {"name": ""},
            "description": "Provides information about the contracts within this container",
            "termsOfService": "",
            "title": "Fabric System Contract",
            "version": "",
            "contact": {}
         }
      }
   },
   "info": {
      "license": {"name": "Apache-2.0"},
      "description": "My Smart Contract",
      "termsOfService": "",
      "title": "MyAssetContract contract",
      "version": "0.0.1",
      "contact": {}
   }
}
2021-10-18 16:58:05.265 [INFO ] [] - org.hyperledger.fabric.contract.ContractRouter-198 - Starting ChaincodeServer
2021-10-18 16:58:05.265 [INFO ] [] - org.hyperledger.fabric.shim.NettyGrpcServer-109 - start grpc server
2021-10-18 16:58:05.285 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.ResourceLeakDetector-130 - -Dio.grpc.netty.shaded.io.netty.leakDetection.level: simple
2021-10-18 16:58:05.286 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.ResourceLeakDetector-131 - -Dio.grpc.netty.shaded.io.netty.leakDetection.targetRecords: 4
2021-10-18 16:58:05.287 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.PooledByteBufAllocator-156 - -Dio.netty.allocator.numHeapArenas: 16
2021-10-18 16:58:05.287 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.PooledByteBufAllocator-157 - -Dio.netty.allocator.numDirectArenas: 16
2021-10-18 16:58:05.287 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.PooledByteBufAllocator-159 - -Dio.netty.allocator.pageSize: 8192
2021-10-18 16:58:05.287 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.PooledByteBufAllocator-164 - -Dio.netty.allocator.maxOrder: 11
2021-10-18 16:58:05.287 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.PooledByteBufAllocator-168 - -Dio.netty.allocator.chunkSize: 16777216
2021-10-18 16:58:05.287 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.PooledByteBufAllocator-169 - -Dio.netty.allocator.tinyCacheSize: 512
2021-10-18 16:58:05.287 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.PooledByteBufAllocator-170 - -Dio.netty.allocator.smallCacheSize: 256
2021-10-18 16:58:05.287 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.PooledByteBufAllocator-171 - -Dio.netty.allocator.normalCacheSize: 64
2021-10-18 16:58:05.287 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.PooledByteBufAllocator-172 - -Dio.netty.allocator.maxCachedBufferCapacity: 32768
2021-10-18 16:58:05.288 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.PooledByteBufAllocator-173 - -Dio.netty.allocator.cacheTrimInterval: 8192
2021-10-18 16:58:05.288 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.PooledByteBufAllocator-174 - -Dio.netty.allocator.cacheTrimIntervalMillis: 0
2021-10-18 16:58:05.288 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.PooledByteBufAllocator-175 - -Dio.netty.allocator.useCacheForAllThreads: true
2021-10-18 16:58:05.288 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.PooledByteBufAllocator-176 - -Dio.netty.allocator.maxCachedByteBuffersPerChunk: 1023
2021-10-18 16:58:05.308 [DEBUG] [] - io.grpc.netty.shaded.io.netty.channel.DefaultChannelId-79 - -Dio.netty.processId: 252300 (auto-detected)
2021-10-18 16:58:05.310 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.NetUtil-139 - -Djava.net.preferIPv4Stack: false
2021-10-18 16:58:05.311 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.NetUtil-140 - -Djava.net.preferIPv6Addresses: false
2021-10-18 16:58:06.232 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.NetUtil-224 - Loopback interface: lo (Software Loopback Interface 1, 127.0.0.1)
2021-10-18 16:58:06.233 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.NetUtil-289 - Failed to get SOMAXCONN from sysctl and file \proc\sys\net\core\somaxconn. Default: 200
2021-10-18 16:58:07.226 [DEBUG] [] - io.grpc.netty.shaded.io.netty.channel.DefaultChannelId-101 - -Dio.netty.machineId: e8:6a:64:ff:fe:71:3c:b1 (auto-detected)
2021-10-18 16:58:07.247 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.ByteBufUtil-86 - -Dio.netty.allocator.type: pooled
2021-10-18 16:58:07.247 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.ByteBufUtil-95 - -Dio.netty.threadLocalDirectBufferSize: 0
2021-10-18 16:58:07.247 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.ByteBufUtil-98 - -Dio.netty.maxThreadLocalCharBufferSize: 16384
2021-10-18 16:58:07.259 [INFO ] [] - org.hyperledger.fabric.shim.NettyGrpcServer-127 - Waits for the server to become terminated.

When I invoke the contract method, the log in contract service shows:

(ignore logs by io.grpc.netty.shaded.io.grpc.netty.NettyServerHandler line 214 and 191)
2021-10-18 17:02:14.862 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.AbstractByteBuf-63 - -Dio.grpc.netty.shaded.io.netty.buffer.checkAccessible: true
2021-10-18 17:02:14.863 [DEBUG] [] - io.grpc.netty.shaded.io.netty.buffer.AbstractByteBuf-64 - -Dio.grpc.netty.shaded.io.netty.buffer.checkBounds: true
2021-10-18 17:02:14.865 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.ResourceLeakDetectorFactory-195 - Loaded default ResourceLeakDetector: io.grpc.netty.shaded.io.netty.util.ResourceLeakDetector@17d8818a
2021-10-18 17:02:14.964 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.Recycler-97 - -Dio.netty.recycler.maxCapacityPerThread: 4096
2021-10-18 17:02:14.964 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.Recycler-98 - -Dio.netty.recycler.maxSharedCapacityFactor: 2
2021-10-18 17:02:14.964 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.Recycler-99 - -Dio.netty.recycler.linkCapacity: 16
2021-10-18 17:02:14.965 [DEBUG] [] - io.grpc.netty.shaded.io.netty.util.Recycler-100 - -Dio.netty.recycler.ratio: 8
2021-10-18 17:02:15.086 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-486 - Configuring channel connection to peer.
2021-10-18 17:02:15.086 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-486 - Configuring channel connection to peer.
2021-10-18 17:02:15.086 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-486 - Configuring channel connection to peer.
2021-10-18 17:02:15.086 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-486 - Configuring channel connection to peer.
2021-10-18 17:02:15.086 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-486 - Configuring channel connection to peer.
2021-10-18 17:02:15.086 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-486 - Configuring channel connection to peer.
2021-10-18 17:02:15.086 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-486 - Configuring channel connection to peer.
2021-10-18 17:02:15.086 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-486 - Configuring channel connection to peer.
2021-10-18 17:02:15.087 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-124 - Maximum Inbound Message Size [MAX_INBOUND_MESSAGE_SIZE] = 104857600
2021-10-18 17:02:15.087 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-124 - Maximum Inbound Message Size [MAX_INBOUND_MESSAGE_SIZE] = 104857600
2021-10-18 17:02:15.086 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-486 - Configuring channel connection to peer.
2021-10-18 17:02:15.087 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-124 - Maximum Inbound Message Size [MAX_INBOUND_MESSAGE_SIZE] = 104857600
2021-10-18 17:02:15.086 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-486 - Configuring channel connection to peer.
2021-10-18 17:02:15.086 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-486 - Configuring channel connection to peer.
2021-10-18 17:02:15.086 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-486 - Configuring channel connection to peer.
2021-10-18 17:02:15.087 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-124 - Maximum Inbound Message Size [MAX_INBOUND_MESSAGE_SIZE] = 104857600
2021-10-18 17:02:15.087 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-124 - Maximum Inbound Message Size [MAX_INBOUND_MESSAGE_SIZE] = 104857600
2021-10-18 17:02:15.087 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-124 - Maximum Inbound Message Size [MAX_INBOUND_MESSAGE_SIZE] = 104857600
2021-10-18 17:02:15.087 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-124 - Maximum Inbound Message Size [MAX_INBOUND_MESSAGE_SIZE] = 104857600
2021-10-18 17:02:15.087 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-124 - Maximum Inbound Message Size [MAX_INBOUND_MESSAGE_SIZE] = 104857600
2021-10-18 17:02:15.087 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-124 - Maximum Inbound Message Size [MAX_INBOUND_MESSAGE_SIZE] = 104857600
2021-10-18 17:02:15.087 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-124 - Maximum Inbound Message Size [MAX_INBOUND_MESSAGE_SIZE] = 104857600
2021-10-18 17:02:15.087 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-124 - Maximum Inbound Message Size [MAX_INBOUND_MESSAGE_SIZE] = 104857600
2021-10-18 17:02:15.087 [INFO ] [] - org.hyperledger.fabric.shim.ChaincodeBase-124 - Maximum Inbound Message Size [MAX_INBOUND_MESSAGE_SIZE] = 104857600
2021-10-18 17:02:15.142 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-125 - Max Pool Size [TP_MAX_POOL_SIZE]5
2021-10-18 17:02:15.143 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-126 - Queue Size [TP_CORE_POOL_SIZE]5000
2021-10-18 17:02:15.143 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-126 - Queue Size [TP_CORE_POOL_SIZE]5000
2021-10-18 17:02:15.143 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-126 - Queue Size [TP_CORE_POOL_SIZE]5000
2021-10-18 17:02:15.143 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-126 - Queue Size [TP_CORE_POOL_SIZE]5000
2021-10-18 17:02:15.143 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-126 - Queue Size [TP_CORE_POOL_SIZE]5000
2021-10-18 17:02:15.142 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-125 - Max Pool Size [TP_MAX_POOL_SIZE]5
2021-10-18 17:02:15.143 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-127 - Core Pool Size [TP_QUEUE_SIZE]5
2021-10-18 17:02:15.144 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-126 - Queue Size [TP_CORE_POOL_SIZE]5000
2021-10-18 17:02:15.144 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-127 - Core Pool Size [TP_QUEUE_SIZE]5
2021-10-18 17:02:15.144 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-127 - Core Pool Size [TP_QUEUE_SIZE]5
2021-10-18 17:02:15.144 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-126 - Queue Size [TP_CORE_POOL_SIZE]5000
2021-10-18 17:02:15.144 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-127 - Core Pool Size [TP_QUEUE_SIZE]5
2021-10-18 17:02:15.144 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-127 - Core Pool Size [TP_QUEUE_SIZE]5
2021-10-18 17:02:15.144 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-128 - Keep Alive Time [TP_KEEP_ALIVE_MS]5000
2021-10-18 17:02:15.144 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-128 - Keep Alive Time [TP_KEEP_ALIVE_MS]5000
2021-10-18 17:02:15.144 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-128 - Keep Alive Time [TP_KEEP_ALIVE_MS]5000
2021-10-18 17:02:15.144 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-128 - Keep Alive Time [TP_KEEP_ALIVE_MS]5000
2021-10-18 17:02:15.144 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-128 - Keep Alive Time [TP_KEEP_ALIVE_MS]5000
2021-10-18 17:02:15.143 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-127 - Core Pool Size [TP_QUEUE_SIZE]5
2021-10-18 17:02:15.143 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-125 - Max Pool Size [TP_MAX_POOL_SIZE]5
2021-10-18 17:02:15.143 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-125 - Max Pool Size [TP_MAX_POOL_SIZE]5
2021-10-18 17:02:15.142 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-125 - Max Pool Size [TP_MAX_POOL_SIZE]5
2021-10-18 17:02:15.145 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-128 - Keep Alive Time [TP_KEEP_ALIVE_MS]5000
2021-10-18 17:02:15.145 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-126 - Queue Size [TP_CORE_POOL_SIZE]5000
2021-10-18 17:02:15.143 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-126 - Queue Size [TP_CORE_POOL_SIZE]5000
2021-10-18 17:02:15.145 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-127 - Core Pool Size [TP_QUEUE_SIZE]5
2021-10-18 17:02:15.145 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskExecutor-40 - Thread pool created
2021-10-18 17:02:15.143 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-126 - Queue Size [TP_CORE_POOL_SIZE]5000
2021-10-18 17:02:15.147 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-127 - Core Pool Size [TP_QUEUE_SIZE]5
2021-10-18 17:02:15.143 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-127 - Core Pool Size [TP_QUEUE_SIZE]5
2021-10-18 17:02:15.145 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-126 - Queue Size [TP_CORE_POOL_SIZE]5000
2021-10-18 17:02:15.147 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-128 - Keep Alive Time [TP_KEEP_ALIVE_MS]5000
2021-10-18 17:02:15.147 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-128 - Keep Alive Time [TP_KEEP_ALIVE_MS]5000
2021-10-18 17:02:15.147 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-127 - Core Pool Size [TP_QUEUE_SIZE]5
2021-10-18 17:02:15.147 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskExecutor-40 - Thread pool created
2021-10-18 17:02:15.145 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-126 - Queue Size [TP_CORE_POOL_SIZE]5000
2021-10-18 17:02:15.147 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-128 - Keep Alive Time [TP_KEEP_ALIVE_MS]5000
2021-10-18 17:02:15.145 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-127 - Core Pool Size [TP_QUEUE_SIZE]5
2021-10-18 17:02:15.145 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-128 - Keep Alive Time [TP_KEEP_ALIVE_MS]5000
2021-10-18 17:02:15.146 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskExecutor-40 - Thread pool created
2021-10-18 17:02:15.146 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskExecutor-40 - Thread pool created
2021-10-18 17:02:15.149 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskExecutor-40 - Thread pool created
2021-10-18 17:02:15.146 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskExecutor-40 - Thread pool created
2021-10-18 17:02:15.149 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-128 - Keep Alive Time [TP_KEEP_ALIVE_MS]5000
2021-10-18 17:02:15.149 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskExecutor-40 - Thread pool created
2021-10-18 17:02:15.150 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskExecutor-40 - Thread pool created
2021-10-18 17:02:15.146 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskExecutor-40 - Thread pool created
2021-10-18 17:02:15.147 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskExecutor-40 - Thread pool created
2021-10-18 17:02:15.147 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-127 - Core Pool Size [TP_QUEUE_SIZE]5
2021-10-18 17:02:15.150 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskExecutor-40 - Thread pool created
2021-10-18 17:02:15.151 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-128 - Keep Alive Time [TP_KEEP_ALIVE_MS]5000
2021-10-18 17:02:15.152 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskExecutor-40 - Thread pool created
2021-10-18 17:02:15.217 [INFO ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-315 - Registering new chaincode name: "myAssetContract:bb0caa4c55ad6d7d3e58244b436c3858ed9d9726c4efccc0e75852d5523f0042"
(and 11 more...)
2021-10-18 17:02:15.266 [WARN ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-169 - [        ] Received REGISTERED: cannot handle
2021-10-18 17:02:15.276 [WARN ] [] - org.hyperledger.fabric.shim.impl.InvocationTaskManager-209 - [        ] Received READY: cannot handle

and my invkoe result:

failed to execute transaction c44f03af9a179de32a5a724343e0a509b8d30282daa34375db01b9deffd52ad1: error sending: timeout expired while executing transaction

score 0 · Answer 1 · answered Oct 21 '21 at 11:47

Many things can go wrong when setting up a new project for smart contract development. One recommendation is that before linking up with a spring boot project and writing your chaincode functions, start with a known reference and use this to troubleshoot any problems with the environment. Once you have a working reference it should be easier to introduce your contract logic, or set up a new project using the example as a template.

For instance, we have had great results using the new test-network-k8s to build chaincode-as-a-service based smart contracts. This platform reconstructs the test network on a local Kubernetes cluster, and can be used to build and edit chaincode contracts running within a debugger (E.g. IntelliJ, Eclipse, VSCode, etc.) or docker container on the local machine. The kube test network also includes a pre-configured external builder, so it should be "ready to go" with minimal or no configuration.

The Fabric Documentation suggests that Go and Node are the only supported platforms for external builders, but this is incorrect - Java is supported despite the lack of good examples in the fabric-samples project. See Issue #2916 for additional details.

Some helpful links that can help you get started with a Java external service:

Issue #2916, describing a need for a reference Java sample in fabric-samples. Notice that in this ticket the users also report that the chaincode is always "timing out."
test-network-k8s: Alternate development platform for writing smart contracts as a service.
DEBUGGING CHAINCODE

score 0 · Answer 2 · answered May 18 '22 at 12:39

I ran into a similar issue while using java 8 to build chaincode container for chaincode written using fabric shim 2.2.2. After building the container with java 11, the transactions were successful.

Java 11 is the supported version for any release post Fabric 1.4. Building the chaincode container with jdk 11 would be a common fix in this case.

Hyperledger Fabric Invoke Java Chaincode(as a external service) timeout

2 Answers2