Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fabric Gateway not taking intermediate certificate into account #3224

Closed
afrancoc2000 opened this issue Feb 11, 2022 · 15 comments · Fixed by #3225
Closed

Fabric Gateway not taking intermediate certificate into account #3224

afrancoc2000 opened this issue Feb 11, 2022 · 15 comments · Fixed by #3225
Assignees
Labels

Comments

@afrancoc2000
Copy link
Contributor

Hi,

I'm having trouble making the "Hyperledger Fabric Gateway for Go" execute a smart contract, although I am using it successfully for listening to events.

This is the error I get in the client:

Submit error with gRPC status DeadlineExceeded: rpc error: code = DeadlineExceeded desc = context deadline exceeded

This is the error I get in the orderer:

Server TLS handshake failed in 2.628549ms with error remote error: tls: bad certificate server=Orderer remoteaddress=10.250.37.115:40858

This is the error I get in the peer:

Client TLS handshake failed after 6.156747ms with error: x509: certificate signed by unknown authority remoteaddress=10.250.37.195:443

The IP 10.250.37.195 corresponds to the ingress service external IP and the 10.250.37.115 corresponds to the ingress controller. The ingress controller has ssl-passtrough configured so the certificates are not being overridden by it.

I'm using a chain certificate that begins with an ica cert and then on the same file the root certificate, this chain.crt file is stored in the orderers in this folder: "/var/hyperledger/orderer/tls/chain.crt" both ORDERER_GENERAL_TLS_ROOTCAS and ORDERER_GENERAL_TLS_CLIENTROOTCAS point to it.

I tested my tls certificate against the chain.crt using openssl and the answer is ok.

I tested my code against the test network and it works, also using the old node SDK the connection works too.

This is my code (deleting err handling for readability):

func NewGrpcConnection(fabricConfig config.FabricConfig) (*grpc.ClientConn, error) {
    caRootPem, err := loadPemFile(fabricConfig.TlsCaRootPath)
    caIcaPem, err := loadPemFile(fabricConfig.TlsCaIcaPath)
    keypair, err := loadCertificateKeyPair(fabricConfig.TlsCertPath, fabricConfig.TlsKeyPath)

    certPool := x509.NewCertPool()
    certPool.AppendCertsFromPEM(caRootPem)
    certPool.AppendCertsFromPEM(caIcaPem)

    transportCredentials := credentials.NewTLS(&tls.Config{
        ServerName:   fabricConfig.HostName,
        RootCAs:      certPool,
        ClientCAs:    certPool,
        Certificates: []tls.Certificate{*keypair},
    })

    connection, err := grpc.Dial(fabricConfig.PeerEndpoint, grpc.WithTransportCredentials(transportCredentials))
    return connection, nil
}

func NewGateway(clientConnection *grpc.ClientConn, fabricConfig config.FabricConfig) (*client.Gateway, error) {
    id, err := newIdentity(fabricConfig.CertPath, fabricConfig.OrgName)
    sign, err := newSign(fabricConfig.KeyPath)

    gateway, err := client.Connect(
        id,
        client.WithSign(sign),
        client.WithClientConnection(clientConnection),
        client.WithEvaluateTimeout(5*time.Second),
        client.WithEndorseTimeout(15*time.Second),
        client.WithSubmitTimeout(5*time.Second),
        client.WithCommitStatusTimeout(1*time.Minute),
    )

    return gateway, err
}

func main() {
    grpcConnection, err := fabric.NewGrpcConnection(*clientConfig.FabricConfig)
    defer grpcConnection.Close()

    gateway, err := fabric.NewGateway(grpcConnection, *clientConfig.FabricConfig)
    defer gateway.Close()

    network := gateway.GetNetwork(clientConfig.FabricConfig.ChannelName)
    contract := network.GetContract(clientConfig.FabricConfig.ContractName)

result, err = contract.SubmitTransaction(request.Fcn, request.Args...)
}

I tried also overiding the pod's ssl certificates by adding the ca certificates to /usr/local/share/ca-certificates/ and using the update-ca-certificates command with no luck.

I posted a question in the hyperledger chat in here and thanks to the help of @yacovm we found that the intermediate CA certificate is not being taken into acount as can be seen here

Adding the intermediate certificate should fix the problem.

Thanks

@yacovm
Copy link
Contributor

yacovm commented Feb 11, 2022

@andrew-coleman

@afrancoc2000
Copy link
Contributor Author

These are the logs from my peer:

Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.516 UTC 0bb5 INFO [endorser] callChaincode -> finished chaincode: contratocomercializacion duration: 219ms channel=canalp2pdllo txID=a45c0de3
Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.520 UTC 0bb6 INFO [comm.grpc.server] 1 -> unary call completed grpc.service=gateway.Gateway grpc.method=Endorse grpc.request_deadline=2022-02-10T22:58:43.295Z grpc.peer_address=10.250.37.48:52450 grpc.peer_subject="CN=admin-tls@blockchainnp.company.com.co,OU=admin,O=company,L=MEDELLIN,ST=ANTIOQUIA,C=CO" grpc.code=OK grpc.call_duration=224.686647ms
Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.627 UTC [grpc] WarningDepth -> DEBU ad1 [core]Adjusting keepalive ping interval to minimum period of 10s
Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.628 UTC [grpc] InfoDepth -> DEBU ad2 [core]parsed scheme: ""
Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.628 UTC [grpc] InfoDepth -> DEBU ad3 [core]scheme "" not registered, fallback to default scheme
Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.628 UTC [grpc] InfoDepth -> DEBU ad4 [core]ccResolverWrapper: sending update to cc: {[{orderer1.blockchainnp.company.com.co:443 <nil> 0 <nil>}] <nil> <nil>}
Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.629 UTC [grpc] InfoDepth -> DEBU ad5 [core]ClientConn switching balancer to "pick_first"
Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.629 UTC [grpc] InfoDepth -> DEBU ad6 [core]Channel switches to new LB policy "pick_first"
Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.629 UTC [grpc] InfoDepth -> DEBU ad7 [core]Subchannel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.629 UTC [grpc] InfoDepth -> DEBU ad8 [core]Subchannel picks a new address "orderer1.blockchainnp.company.com.co:443" to connect
Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.630 UTC [grpc] InfoDepth -> DEBU ad9 [core]pickfirstBalancer: UpdateSubConnState: 0xc0075d72b0, {CONNECTING <nil>}
Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.630 UTC [grpc] InfoDepth -> DEBU ada [core]Channel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.896 UTC 0bb7 ERRO [comm.tls] ClientHandshake -> Client TLS handshake failed after 4.17472ms with error: x509: certificate signed by unknown authority remoteaddress=10.250.37.195:443
Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.896 UTC [grpc] WarningDepth -> DEBU adb [core]grpc: addrConn.createTransport failed to connect to {orderer1.blockchainnp.company.com.co:443 orderer1.blockchainnp.company.com.co:443 <nil> 0 <nil>}. Err: connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority". Reconnecting...
Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.897 UTC [grpc] InfoDepth -> DEBU adc [core]Subchannel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.897 UTC [grpc] InfoDepth -> DEBU add [core]pickfirstBalancer: UpdateSubConnState: 0xc0075d72b0, {TRANSIENT_FAILURE connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority"}
Thu, Feb 10 2022 5:58:28 pm	2022-02-10 22:58:28.899 UTC [grpc] InfoDepth -> DEBU ade [core]Channel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:29 pm	2022-02-10 22:58:29.898 UTC [grpc] InfoDepth -> DEBU adf [core]Subchannel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:29 pm	2022-02-10 22:58:29.898 UTC [grpc] InfoDepth -> DEBU ae1 [core]pickfirstBalancer: UpdateSubConnState: 0xc0075d72b0, {CONNECTING <nil>}
Thu, Feb 10 2022 5:58:29 pm	2022-02-10 22:58:29.898 UTC [grpc] InfoDepth -> DEBU ae2 [core]Channel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:29 pm	2022-02-10 22:58:29.898 UTC [grpc] InfoDepth -> DEBU ae0 [core]Subchannel picks a new address "orderer1.blockchainnp.company.com.co:443" to connect
Thu, Feb 10 2022 5:58:29 pm	2022-02-10 22:58:29.993 UTC 0bb8 ERRO [comm.tls] ClientHandshake -> Client TLS handshake failed after 1.605508ms with error: x509: certificate signed by unknown authority remoteaddress=10.250.37.195:443
Thu, Feb 10 2022 5:58:29 pm	2022-02-10 22:58:29.993 UTC [grpc] WarningDepth -> DEBU ae3 [core]grpc: addrConn.createTransport failed to connect to {orderer1.blockchainnp.company.com.co:443 orderer1.blockchainnp.company.com.co:443 <nil> 0 <nil>}. Err: connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority". Reconnecting...
Thu, Feb 10 2022 5:58:29 pm	2022-02-10 22:58:29.993 UTC [grpc] InfoDepth -> DEBU ae4 [core]Subchannel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:29 pm	2022-02-10 22:58:29.994 UTC [grpc] InfoDepth -> DEBU ae5 [core]pickfirstBalancer: UpdateSubConnState: 0xc0075d72b0, {TRANSIENT_FAILURE connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority"}
Thu, Feb 10 2022 5:58:29 pm	2022-02-10 22:58:29.994 UTC [grpc] InfoDepth -> DEBU ae6 [core]Channel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:31 pm	2022-02-10 22:58:31.594 UTC [grpc] InfoDepth -> DEBU ae7 [core]Subchannel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:31 pm	2022-02-10 22:58:31.595 UTC [grpc] InfoDepth -> DEBU ae8 [core]pickfirstBalancer: UpdateSubConnState: 0xc0075d72b0, {CONNECTING <nil>}
Thu, Feb 10 2022 5:58:31 pm	2022-02-10 22:58:31.595 UTC [grpc] InfoDepth -> DEBU ae9 [core]Channel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:31 pm	2022-02-10 22:58:31.595 UTC [grpc] InfoDepth -> DEBU aea [core]Subchannel picks a new address "orderer1.blockchainnp.company.com.co:443" to connect
Thu, Feb 10 2022 5:58:31 pm	2022-02-10 22:58:31.695 UTC 0bb9 ERRO [comm.tls] ClientHandshake -> Client TLS handshake failed after 1.847809ms with error: x509: certificate signed by unknown authority remoteaddress=10.250.37.195:443
Thu, Feb 10 2022 5:58:31 pm	2022-02-10 22:58:31.695 UTC [grpc] WarningDepth -> DEBU aeb [core]grpc: addrConn.createTransport failed to connect to {orderer1.blockchainnp.company.com.co:443 orderer1.blockchainnp.company.com.co:443 <nil> 0 <nil>}. Err: connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority". Reconnecting...
Thu, Feb 10 2022 5:58:31 pm	2022-02-10 22:58:31.697 UTC [grpc] InfoDepth -> DEBU aec [core]Subchannel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:31 pm	2022-02-10 22:58:31.697 UTC [grpc] InfoDepth -> DEBU aed [core]pickfirstBalancer: UpdateSubConnState: 0xc0075d72b0, {TRANSIENT_FAILURE connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority"}
Thu, Feb 10 2022 5:58:31 pm	2022-02-10 22:58:31.697 UTC [grpc] InfoDepth -> DEBU aee [core]Channel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:34 pm	2022-02-10 22:58:34.655 UTC [grpc] InfoDepth -> DEBU aef [core]Subchannel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:34 pm	2022-02-10 22:58:34.656 UTC [grpc] InfoDepth -> DEBU af0 [core]Subchannel picks a new address "orderer1.blockchainnp.company.com.co:443" to connect
Thu, Feb 10 2022 5:58:34 pm	2022-02-10 22:58:34.657 UTC [grpc] InfoDepth -> DEBU af1 [core]pickfirstBalancer: UpdateSubConnState: 0xc0075d72b0, {CONNECTING <nil>}
Thu, Feb 10 2022 5:58:34 pm	2022-02-10 22:58:34.657 UTC [grpc] InfoDepth -> DEBU af2 [core]Channel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:34 pm	2022-02-10 22:58:34.668 UTC 0bba ERRO [comm.tls] ClientHandshake -> Client TLS handshake failed after 2.635212ms with error: x509: certificate signed by unknown authority remoteaddress=10.250.37.195:443
Thu, Feb 10 2022 5:58:34 pm	2022-02-10 22:58:34.670 UTC [grpc] WarningDepth -> DEBU af3 [core]grpc: addrConn.createTransport failed to connect to {orderer1.blockchainnp.company.com.co:443 orderer1.blockchainnp.company.com.co:443 <nil> 0 <nil>}. Err: connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority". Reconnecting...
Thu, Feb 10 2022 5:58:34 pm	2022-02-10 22:58:34.670 UTC [grpc] InfoDepth -> DEBU af4 [core]Subchannel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:34 pm	2022-02-10 22:58:34.670 UTC [grpc] InfoDepth -> DEBU af5 [core]pickfirstBalancer: UpdateSubConnState: 0xc0075d72b0, {TRANSIENT_FAILURE connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority"}
Thu, Feb 10 2022 5:58:34 pm	2022-02-10 22:58:34.670 UTC [grpc] InfoDepth -> DEBU af6 [core]Channel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:38 pm	2022-02-10 22:58:38.322 UTC [grpc] InfoDepth -> DEBU af7 [core]Subchannel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:38 pm	2022-02-10 22:58:38.322 UTC [grpc] InfoDepth -> DEBU af8 [core]Subchannel picks a new address "orderer1.blockchainnp.company.com.co:443" to connect
Thu, Feb 10 2022 5:58:38 pm	2022-02-10 22:58:38.322 UTC [grpc] InfoDepth -> DEBU af9 [core]pickfirstBalancer: UpdateSubConnState: 0xc0075d72b0, {CONNECTING <nil>}
Thu, Feb 10 2022 5:58:38 pm	2022-02-10 22:58:38.325 UTC [grpc] InfoDepth -> DEBU afa [core]Channel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:38 pm	2022-02-10 22:58:38.366 UTC 0bbb ERRO [comm.tls] ClientHandshake -> Client TLS handshake failed after 8.301236ms with error: x509: certificate signed by unknown authority remoteaddress=10.250.37.195:443
Thu, Feb 10 2022 5:58:38 pm	2022-02-10 22:58:38.366 UTC [grpc] WarningDepth -> DEBU afb [core]grpc: addrConn.createTransport failed to connect to {orderer1.blockchainnp.company.com.co:443 orderer1.blockchainnp.company.com.co:443 <nil> 0 <nil>}. Err: connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority". Reconnecting...
Thu, Feb 10 2022 5:58:38 pm	2022-02-10 22:58:38.366 UTC [grpc] InfoDepth -> DEBU afc [core]Subchannel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:38 pm	2022-02-10 22:58:38.366 UTC [grpc] InfoDepth -> DEBU afd [core]pickfirstBalancer: UpdateSubConnState: 0xc0075d72b0, {TRANSIENT_FAILURE connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority"}
Thu, Feb 10 2022 5:58:38 pm	2022-02-10 22:58:38.366 UTC [grpc] InfoDepth -> DEBU afe [core]Channel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:44 pm	2022-02-10 22:58:44.812 UTC [grpc] InfoDepth -> DEBU aff [core]Subchannel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:44 pm	2022-02-10 22:58:44.812 UTC [grpc] InfoDepth -> DEBU b00 [core]Subchannel picks a new address "orderer1.blockchainnp.company.com.co:443" to connect
Thu, Feb 10 2022 5:58:44 pm	2022-02-10 22:58:44.813 UTC [grpc] InfoDepth -> DEBU b01 [core]pickfirstBalancer: UpdateSubConnState: 0xc0075d72b0, {CONNECTING <nil>}
Thu, Feb 10 2022 5:58:44 pm	2022-02-10 22:58:44.813 UTC [grpc] InfoDepth -> DEBU b02 [core]Channel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:44 pm	2022-02-10 22:58:44.824 UTC 0bbc ERRO [comm.tls] ClientHandshake -> Client TLS handshake failed after 3.044214ms with error: x509: certificate signed by unknown authority remoteaddress=10.250.37.195:443
Thu, Feb 10 2022 5:58:44 pm	2022-02-10 22:58:44.826 UTC [grpc] WarningDepth -> DEBU b03 [core]grpc: addrConn.createTransport failed to connect to {orderer1.blockchainnp.company.com.co:443 orderer1.blockchainnp.company.com.co:443 <nil> 0 <nil>}. Err: connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority". Reconnecting...
Thu, Feb 10 2022 5:58:44 pm	2022-02-10 22:58:44.826 UTC [grpc] InfoDepth -> DEBU b04 [core]Subchannel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:44 pm	2022-02-10 22:58:44.827 UTC [grpc] InfoDepth -> DEBU b05 [core]pickfirstBalancer: UpdateSubConnState: 0xc0075d72b0, {TRANSIENT_FAILURE connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority"}
Thu, Feb 10 2022 5:58:44 pm	2022-02-10 22:58:44.829 UTC [grpc] InfoDepth -> DEBU b06 [core]Channel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:54 pm	2022-02-10 22:58:54.437 UTC [grpc] InfoDepth -> DEBU b07 [core]Subchannel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:54 pm	2022-02-10 22:58:54.438 UTC [grpc] InfoDepth -> DEBU b08 [core]Subchannel picks a new address "orderer1.blockchainnp.company.com.co:443" to connect
Thu, Feb 10 2022 5:58:54 pm	2022-02-10 22:58:54.438 UTC [grpc] InfoDepth -> DEBU b09 [core]pickfirstBalancer: UpdateSubConnState: 0xc0075d72b0, {CONNECTING <nil>}
Thu, Feb 10 2022 5:58:54 pm	2022-02-10 22:58:54.438 UTC [grpc] InfoDepth -> DEBU b0a [core]Channel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:54 pm	2022-02-10 22:58:54.451 UTC 0bbd ERRO [comm.tls] ClientHandshake -> Client TLS handshake failed after 1.810108ms with error: x509: certificate signed by unknown authority remoteaddress=10.250.37.195:443
Thu, Feb 10 2022 5:58:54 pm	2022-02-10 22:58:54.453 UTC [grpc] WarningDepth -> DEBU b0b [core]grpc: addrConn.createTransport failed to connect to {orderer1.blockchainnp.company.com.co:443 orderer1.blockchainnp.company.com.co:443 <nil> 0 <nil>}. Err: connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority". Reconnecting...
Thu, Feb 10 2022 5:58:54 pm	2022-02-10 22:58:54.454 UTC [grpc] InfoDepth -> DEBU b0c [core]Subchannel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:54 pm	2022-02-10 22:58:54.454 UTC [grpc] InfoDepth -> DEBU b0d [core]pickfirstBalancer: UpdateSubConnState: 0xc0075d72b0, {TRANSIENT_FAILURE connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority"}
Thu, Feb 10 2022 5:58:54 pm	2022-02-10 22:58:54.455 UTC [grpc] InfoDepth -> DEBU b0e [core]Channel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.629 UTC [grpc] InfoDepth -> DEBU b0f [core]Channel Connectivity change to SHUTDOWN
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.629 UTC [grpc] InfoDepth -> DEBU b10 [core]Subchannel Connectivity change to SHUTDOWN
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.630 UTC 0bbe WARN [gateway] orderers -> Failed to connect to orderer address=orderer1.blockchainnp.company.com.co:443 err="failed to create new connection: context deadline exceeded"
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.630 UTC [grpc] WarningDepth -> DEBU b11 [core]Adjusting keepalive ping interval to minimum period of 10s
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.631 UTC [grpc] InfoDepth -> DEBU b12 [core]parsed scheme: ""
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.632 UTC [grpc] InfoDepth -> DEBU b13 [core]scheme "" not registered, fallback to default scheme
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.633 UTC [grpc] InfoDepth -> DEBU b14 [core]ccResolverWrapper: sending update to cc: {[{orderer2.blockchainnp.company.com.co:443 <nil> 0 <nil>}] <nil> <nil>}
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.633 UTC [grpc] InfoDepth -> DEBU b15 [core]ClientConn switching balancer to "pick_first"
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.633 UTC [grpc] InfoDepth -> DEBU b16 [core]Channel switches to new LB policy "pick_first"
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.633 UTC [grpc] InfoDepth -> DEBU b17 [core]Subchannel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.633 UTC [grpc] InfoDepth -> DEBU b18 [core]Subchannel picks a new address "orderer2.blockchainnp.company.com.co:443" to connect
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.633 UTC [grpc] InfoDepth -> DEBU b19 [core]pickfirstBalancer: UpdateSubConnState: 0xc002632260, {CONNECTING <nil>}
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.633 UTC [grpc] InfoDepth -> DEBU b1a [core]Channel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.887 UTC 0bbf ERRO [comm.tls] ClientHandshake -> Client TLS handshake failed after 9.422744ms with error: x509: certificate signed by unknown authority remoteaddress=10.250.37.195:443
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.887 UTC [grpc] WarningDepth -> DEBU b1b [core]grpc: addrConn.createTransport failed to connect to {orderer2.blockchainnp.company.com.co:443 orderer2.blockchainnp.company.com.co:443 <nil> 0 <nil>}. Err: connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority". Reconnecting...
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.888 UTC [grpc] InfoDepth -> DEBU b1c [core]Subchannel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.888 UTC [grpc] InfoDepth -> DEBU b1d [core]pickfirstBalancer: UpdateSubConnState: 0xc002632260, {TRANSIENT_FAILURE connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority"}
Thu, Feb 10 2022 5:58:58 pm	2022-02-10 22:58:58.888 UTC [grpc] InfoDepth -> DEBU b1e [core]Channel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:59 pm	2022-02-10 22:58:59.888 UTC [grpc] InfoDepth -> DEBU b1f [core]Subchannel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:59 pm	2022-02-10 22:58:59.888 UTC [grpc] InfoDepth -> DEBU b20 [core]Subchannel picks a new address "orderer2.blockchainnp.company.com.co:443" to connect
Thu, Feb 10 2022 5:58:59 pm	2022-02-10 22:58:59.889 UTC [grpc] InfoDepth -> DEBU b21 [core]pickfirstBalancer: UpdateSubConnState: 0xc002632260, {CONNECTING <nil>}
Thu, Feb 10 2022 5:58:59 pm	2022-02-10 22:58:59.889 UTC [grpc] InfoDepth -> DEBU b22 [core]Channel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:58:59 pm	2022-02-10 22:58:59.985 UTC 0bc0 ERRO [comm.tls] ClientHandshake -> Client TLS handshake failed after 5.228425ms with error: x509: certificate signed by unknown authority remoteaddress=10.250.37.195:443
Thu, Feb 10 2022 5:58:59 pm	2022-02-10 22:58:59.986 UTC [grpc] WarningDepth -> DEBU b23 [core]grpc: addrConn.createTransport failed to connect to {orderer2.blockchainnp.company.com.co:443 orderer2.blockchainnp.company.com.co:443 <nil> 0 <nil>}. Err: connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority". Reconnecting...
Thu, Feb 10 2022 5:58:59 pm	2022-02-10 22:58:59.986 UTC [grpc] InfoDepth -> DEBU b24 [core]Subchannel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:58:59 pm	2022-02-10 22:58:59.986 UTC [grpc] InfoDepth -> DEBU b25 [core]pickfirstBalancer: UpdateSubConnState: 0xc002632260, {TRANSIENT_FAILURE connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority"}
Thu, Feb 10 2022 5:58:59 pm	2022-02-10 22:58:59.986 UTC [grpc] InfoDepth -> DEBU b26 [core]Channel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:59:01 pm	2022-02-10 22:59:01.849 UTC [grpc] InfoDepth -> DEBU b27 [core]Subchannel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:59:01 pm	2022-02-10 22:59:01.849 UTC [grpc] InfoDepth -> DEBU b28 [core]Subchannel picks a new address "orderer2.blockchainnp.company.com.co:443" to connect
Thu, Feb 10 2022 5:59:01 pm	2022-02-10 22:59:01.849 UTC [grpc] InfoDepth -> DEBU b29 [core]pickfirstBalancer: UpdateSubConnState: 0xc002632260, {CONNECTING <nil>}
Thu, Feb 10 2022 5:59:01 pm	2022-02-10 22:59:01.850 UTC [grpc] InfoDepth -> DEBU b2a [core]Channel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:59:01 pm	2022-02-10 22:59:01.869 UTC 0bc1 ERRO [comm.tls] ClientHandshake -> Client TLS handshake failed after 6.157629ms with error: x509: certificate signed by unknown authority remoteaddress=10.250.37.195:443
Thu, Feb 10 2022 5:59:01 pm	2022-02-10 22:59:01.869 UTC [grpc] WarningDepth -> DEBU b2b [core]grpc: addrConn.createTransport failed to connect to {orderer2.blockchainnp.company.com.co:443 orderer2.blockchainnp.company.com.co:443 <nil> 0 <nil>}. Err: connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority". Reconnecting...
Thu, Feb 10 2022 5:59:01 pm	2022-02-10 22:59:01.869 UTC [grpc] InfoDepth -> DEBU b2c [core]Subchannel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:59:01 pm	2022-02-10 22:59:01.871 UTC [grpc] InfoDepth -> DEBU b2d [core]pickfirstBalancer: UpdateSubConnState: 0xc002632260, {TRANSIENT_FAILURE connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority"}
Thu, Feb 10 2022 5:59:01 pm	2022-02-10 22:59:01.871 UTC [grpc] InfoDepth -> DEBU b2e [core]Channel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:59:04 pm	2022-02-10 22:59:04.869 UTC [grpc] InfoDepth -> DEBU b2f [core]Subchannel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:59:04 pm	2022-02-10 22:59:04.869 UTC [grpc] InfoDepth -> DEBU b30 [core]Subchannel picks a new address "orderer2.blockchainnp.company.com.co:443" to connect
Thu, Feb 10 2022 5:59:04 pm	2022-02-10 22:59:04.869 UTC [grpc] InfoDepth -> DEBU b31 [core]pickfirstBalancer: UpdateSubConnState: 0xc002632260, {CONNECTING <nil>}
Thu, Feb 10 2022 5:59:04 pm	2022-02-10 22:59:04.873 UTC [grpc] InfoDepth -> DEBU b32 [core]Channel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:59:04 pm	2022-02-10 22:59:04.904 UTC 0bc2 ERRO [comm.tls] ClientHandshake -> Client TLS handshake failed after 6.212829ms with error: x509: certificate signed by unknown authority remoteaddress=10.250.37.195:443
Thu, Feb 10 2022 5:59:04 pm	2022-02-10 22:59:04.905 UTC [grpc] WarningDepth -> DEBU b33 [core]grpc: addrConn.createTransport failed to connect to {orderer2.blockchainnp.company.com.co:443 orderer2.blockchainnp.company.com.co:443 <nil> 0 <nil>}. Err: connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority". Reconnecting...
Thu, Feb 10 2022 5:59:04 pm	2022-02-10 22:59:04.905 UTC [grpc] InfoDepth -> DEBU b34 [core]Subchannel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:59:04 pm	2022-02-10 22:59:04.905 UTC [grpc] InfoDepth -> DEBU b35 [core]pickfirstBalancer: UpdateSubConnState: 0xc002632260, {TRANSIENT_FAILURE connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority"}
Thu, Feb 10 2022 5:59:04 pm	2022-02-10 22:59:04.907 UTC [grpc] InfoDepth -> DEBU b36 [core]Channel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:59:08 pm	2022-02-10 22:59:08.819 UTC [grpc] InfoDepth -> DEBU b37 [core]Subchannel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:59:08 pm	2022-02-10 22:59:08.819 UTC [grpc] InfoDepth -> DEBU b38 [core]pickfirstBalancer: UpdateSubConnState: 0xc002632260, {CONNECTING <nil>}
Thu, Feb 10 2022 5:59:08 pm	2022-02-10 22:59:08.819 UTC [grpc] InfoDepth -> DEBU b39 [core]Channel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:59:08 pm	2022-02-10 22:59:08.819 UTC [grpc] InfoDepth -> DEBU b3a [core]Subchannel picks a new address "orderer2.blockchainnp.company.com.co:443" to connect
Thu, Feb 10 2022 5:59:08 pm	2022-02-10 22:59:08.841 UTC 0bc3 ERRO [comm.tls] ClientHandshake -> Client TLS handshake failed after 5.425925ms with error: x509: certificate signed by unknown authority remoteaddress=10.250.37.195:443
Thu, Feb 10 2022 5:59:08 pm	2022-02-10 22:59:08.842 UTC [grpc] WarningDepth -> DEBU b3b [core]grpc: addrConn.createTransport failed to connect to {orderer2.blockchainnp.company.com.co:443 orderer2.blockchainnp.company.com.co:443 <nil> 0 <nil>}. Err: connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority". Reconnecting...
Thu, Feb 10 2022 5:59:08 pm	2022-02-10 22:59:08.842 UTC [grpc] InfoDepth -> DEBU b3c [core]Subchannel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:59:08 pm	2022-02-10 22:59:08.844 UTC [grpc] InfoDepth -> DEBU b3d [core]pickfirstBalancer: UpdateSubConnState: 0xc002632260, {TRANSIENT_FAILURE connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority"}
Thu, Feb 10 2022 5:59:08 pm	2022-02-10 22:59:08.844 UTC [grpc] InfoDepth -> DEBU b3e [core]Channel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:59:15 pm	2022-02-10 22:59:15.767 UTC [grpc] InfoDepth -> DEBU b3f [core]Subchannel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:59:15 pm	2022-02-10 22:59:15.767 UTC [grpc] InfoDepth -> DEBU b40 [core]pickfirstBalancer: UpdateSubConnState: 0xc002632260, {CONNECTING <nil>}
Thu, Feb 10 2022 5:59:15 pm	2022-02-10 22:59:15.768 UTC [grpc] InfoDepth -> DEBU b41 [core]Channel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:59:15 pm	2022-02-10 22:59:15.768 UTC [grpc] InfoDepth -> DEBU b42 [core]Subchannel picks a new address "orderer2.blockchainnp.company.com.co:443" to connect
Thu, Feb 10 2022 5:59:15 pm	2022-02-10 22:59:15.795 UTC 0bc4 ERRO [comm.tls] ClientHandshake -> Client TLS handshake failed after 13.602464ms with error: x509: certificate signed by unknown authority remoteaddress=10.250.37.195:443
Thu, Feb 10 2022 5:59:15 pm	2022-02-10 22:59:15.795 UTC [grpc] WarningDepth -> DEBU b43 [core]grpc: addrConn.createTransport failed to connect to {orderer2.blockchainnp.company.com.co:443 orderer2.blockchainnp.company.com.co:443 <nil> 0 <nil>}. Err: connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority". Reconnecting...
Thu, Feb 10 2022 5:59:15 pm	2022-02-10 22:59:15.797 UTC [grpc] InfoDepth -> DEBU b44 [core]Subchannel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:59:15 pm	2022-02-10 22:59:15.798 UTC [grpc] InfoDepth -> DEBU b45 [core]pickfirstBalancer: UpdateSubConnState: 0xc002632260, {TRANSIENT_FAILURE connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority"}
Thu, Feb 10 2022 5:59:15 pm	2022-02-10 22:59:15.798 UTC [grpc] InfoDepth -> DEBU b46 [core]Channel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:59:25 pm	2022-02-10 22:59:25.225 UTC [grpc] InfoDepth -> DEBU b47 [core]Subchannel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:59:25 pm	2022-02-10 22:59:25.225 UTC [grpc] InfoDepth -> DEBU b48 [core]Subchannel picks a new address "orderer2.blockchainnp.company.com.co:443" to connect
Thu, Feb 10 2022 5:59:25 pm	2022-02-10 22:59:25.225 UTC [grpc] InfoDepth -> DEBU b49 [core]pickfirstBalancer: UpdateSubConnState: 0xc002632260, {CONNECTING <nil>}
Thu, Feb 10 2022 5:59:25 pm	2022-02-10 22:59:25.225 UTC [grpc] InfoDepth -> DEBU b4a [core]Channel Connectivity change to CONNECTING
Thu, Feb 10 2022 5:59:25 pm	2022-02-10 22:59:25.328 UTC 0bc5 ERRO [comm.tls] ClientHandshake -> Client TLS handshake failed after 85.665298ms with error: x509: certificate signed by unknown authority remoteaddress=10.250.37.195:443
Thu, Feb 10 2022 5:59:25 pm	2022-02-10 22:59:25.329 UTC [grpc] WarningDepth -> DEBU b4b [core]grpc: addrConn.createTransport failed to connect to {orderer2.blockchainnp.company.com.co:443 orderer2.blockchainnp.company.com.co:443 <nil> 0 <nil>}. Err: connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority". Reconnecting...
Thu, Feb 10 2022 5:59:25 pm	2022-02-10 22:59:25.329 UTC [grpc] InfoDepth -> DEBU b4c [core]Subchannel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:59:25 pm	2022-02-10 22:59:25.329 UTC [grpc] InfoDepth -> DEBU b4d [core]pickfirstBalancer: UpdateSubConnState: 0xc002632260, {TRANSIENT_FAILURE connection error: desc = "transport: authentication handshake failed: x509: certificate signed by unknown authority"}
Thu, Feb 10 2022 5:59:25 pm	2022-02-10 22:59:25.329 UTC [grpc] InfoDepth -> DEBU b4e [core]Channel Connectivity change to TRANSIENT_FAILURE
Thu, Feb 10 2022 5:59:28 pm	2022-02-10 22:59:28.632 UTC [grpc] InfoDepth -> DEBU b4f [core]Channel Connectivity change to SHUTDOWN
Thu, Feb 10 2022 5:59:28 pm	2022-02-10 22:59:28.632 UTC [grpc] InfoDepth -> DEBU b50 [core]Subchannel Connectivity change to SHUTDOWN
Thu, Feb 10 2022 5:59:28 pm	2022-02-10 22:59:28.633 UTC 0bc6 WARN [gateway] orderers -> Failed to connect to orderer address=orderer2.blockchainnp.company.com.co:443 err="failed to create new connection: context deadline exceeded"
Thu, Feb 10 2022 5:59:28 pm	2022-02-10 22:59:28.633 UTC 0bc7 INFO [comm.grpc.server] 1 -> unary call completed grpc.service=gateway.Gateway grpc.method=Submit grpc.request_deadline=2022-02-10T22:58:33.616Z grpc.peer_address=10.250.37.48:52450 grpc.peer_subject="CN=admin-tls@blockchainnp.company.com.co,OU=admin,O=company,L=MEDELLIN,ST=ANTIOQUIA,C=CO" error="rpc error: code = Unavailable desc = no orderer nodes available" grpc.code=Unavailable grpc.call_duration=1m0.006300406s

@yacovm
Copy link
Contributor

yacovm commented Feb 11, 2022

@afrancoc2000 the fix has been merged

@denyeart
Copy link
Contributor

Fix backported to release-2.4 for inclusion in v2.4.3.

@afrancoc2000
Copy link
Contributor Author

@yacovm and @denyeart I will try it right now, Thank you!!

@andrew-coleman
Copy link
Member

Hi @afrancoc2000, before we release v2.4.3, could you confirm whether this fix works for you, please? Thanks!

@afrancoc2000
Copy link
Contributor Author

afrancoc2000 commented Feb 15, 2022

Hi @andrew-coleman although I'm not getting the "certificate signed by unknown authority" error, the client still doesn't work, I'm getting now an error on the orderer telling me that the client didn't provide a tls certificate.

These are the logs in the client:

Submit error with gRPC status DeadlineExceeded: rpc error: code = DeadlineExceeded desc = context deadline exceeded

These are the logs in the peer:

[34m2022-02-15 14:43:52.291 UTC 02cd INFO[0m [gateway] [34;1mlookupEndorser[0m -> Attempting to connect to endorser endpoint=10.250.37.121:443
[36m2022-02-15 14:43:52.292 UTC [grpc] WarningDepth -> DEBU 9dd[0m [core]Adjusting keepalive ping interval to minimum period of 10s
[36m2022-02-15 14:43:52.292 UTC [grpc] InfoDepth -> DEBU 9de[0m [core]parsed scheme: ""
[36m2022-02-15 14:43:52.292 UTC [grpc] InfoDepth -> DEBU 9df[0m [core]scheme "" not registered, fallback to default scheme
[36m2022-02-15 14:43:52.292 UTC [grpc] InfoDepth -> DEBU 9e0[0m [core]ccResolverWrapper: sending update to cc: {[{10.250.37.121:443  <nil> 0 <nil>}] <nil> <nil>}
[36m2022-02-15 14:43:52.293 UTC [grpc] InfoDepth -> DEBU 9e1[0m [core]ClientConn switching balancer to "pick_first"
[36m2022-02-15 14:43:52.293 UTC [grpc] InfoDepth -> DEBU 9e2[0m [core]Channel switches to new LB policy "pick_first"
[36m2022-02-15 14:43:52.293 UTC [grpc] InfoDepth -> DEBU 9e3[0m [core]Subchannel Connectivity change to CONNECTING
[36m2022-02-15 14:43:52.293 UTC [grpc] InfoDepth -> DEBU 9e4[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc00385bc70, {CONNECTING <nil>}
[36m2022-02-15 14:43:52.293 UTC [grpc] InfoDepth -> DEBU 9e5[0m [core]Channel Connectivity change to CONNECTING
[36m2022-02-15 14:43:52.293 UTC [grpc] InfoDepth -> DEBU 9e6[0m [core]Subchannel picks a new address "10.250.37.121:443" to connect
[36m2022-02-15 14:43:52.293 UTC [grpc] WarningDepth -> DEBU 9e7[0m [core]grpc: addrConn.createTransport failed to connect to {10.250.37.121:443 10.250.37.121:443 <nil> 0 <nil>}. Err: connection error: desc = "transport: error while dialing: dial tcp 10.250.37.121:443: connect: connection refused". Reconnecting...
[36m2022-02-15 14:43:52.293 UTC [grpc] InfoDepth -> DEBU 9e8[0m [core]Subchannel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:43:52.293 UTC [grpc] InfoDepth -> DEBU 9e9[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc00385bc70, {TRANSIENT_FAILURE connection error: desc = "transport: error while dialing: dial tcp 10.250.37.121:443: connect: connection refused"}
[36m2022-02-15 14:43:52.293 UTC [grpc] InfoDepth -> DEBU 9ea[0m [core]Channel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:43:52.293 UTC [grpc] InfoDepth -> DEBU 9eb[0m [core]Channel Connectivity change to SHUTDOWN
[36m2022-02-15 14:43:52.293 UTC [grpc] InfoDepth -> DEBU 9ec[0m [core]Subchannel Connectivity change to SHUTDOWN
[31m2022-02-15 14:43:52.293 UTC 02ce ERRO[0m [gateway] [31;1mlookupEndorser[0m -> Failed to reconnect endpoint=10.250.37.121:443 err="failed to create new connection: connection error: desc = \"transport: error while dialing: dial tcp 10.250.37.121:443: connect: connection refused\""
[34m2022-02-15 14:43:52.408 UTC 02cf INFO[0m [endorser] [34;1mcallChaincode[0m -> finished chaincode: contratocomercializacion duration: 106ms channel=canalp2pdllo txID=da1f88f3
[34m2022-02-15 14:43:52.410 UTC 02d0 INFO[0m [gateway] [34;1mlookupEndorser[0m -> Attempting to connect to endorser endpoint=peer2.blockchainnp.company.com.co:443
[36m2022-02-15 14:43:52.410 UTC [grpc] WarningDepth -> DEBU 9ed[0m [core]Adjusting keepalive ping interval to minimum period of 10s
[36m2022-02-15 14:43:52.411 UTC [grpc] InfoDepth -> DEBU 9ee[0m [core]parsed scheme: ""
[36m2022-02-15 14:43:52.411 UTC [grpc] InfoDepth -> DEBU 9ef[0m [core]scheme "" not registered, fallback to default scheme
[36m2022-02-15 14:43:52.411 UTC [grpc] InfoDepth -> DEBU 9f0[0m [core]ccResolverWrapper: sending update to cc: {[{10.250.37.121:443  <nil> 0 <nil>}] <nil> <nil>}
[36m2022-02-15 14:43:52.411 UTC [grpc] InfoDepth -> DEBU 9f1[0m [core]ClientConn switching balancer to "pick_first"
[36m2022-02-15 14:43:52.411 UTC [grpc] InfoDepth -> DEBU 9f2[0m [core]Channel switches to new LB policy "pick_first"
[36m2022-02-15 14:43:52.411 UTC [grpc] InfoDepth -> DEBU 9f3[0m [core]Subchannel Connectivity change to CONNECTING
[36m2022-02-15 14:43:52.412 UTC [grpc] InfoDepth -> DEBU 9f4[0m [core]Subchannel picks a new address "10.250.37.121:443" to connect
[36m2022-02-15 14:43:52.412 UTC [grpc] InfoDepth -> DEBU 9f5[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc003f88970, {CONNECTING <nil>}
[36m2022-02-15 14:43:52.412 UTC [grpc] InfoDepth -> DEBU 9f6[0m [core]Channel Connectivity change to CONNECTING
[36m2022-02-15 14:43:52.413 UTC [grpc] WarningDepth -> DEBU 9f7[0m [core]grpc: addrConn.createTransport failed to connect to {10.250.37.121:443 10.250.37.121:443 <nil> 0 <nil>}. Err: connection error: desc = "transport: error while dialing: dial tcp 10.250.37.121:443: connect: connection refused". Reconnecting...
[36m2022-02-15 14:43:52.413 UTC [grpc] InfoDepth -> DEBU 9f8[0m [core]Subchannel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:43:52.413 UTC [grpc] InfoDepth -> DEBU 9f9[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc003f88970, {TRANSIENT_FAILURE connection error: desc = "transport: error while dialing: dial tcp 10.250.37.121:443: connect: connection refused"}
[36m2022-02-15 14:43:52.413 UTC [grpc] InfoDepth -> DEBU 9fa[0m [core]Channel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:43:52.415 UTC [grpc] InfoDepth -> DEBU 9fb[0m [core]Channel Connectivity change to SHUTDOWN
[36m2022-02-15 14:43:52.415 UTC [grpc] InfoDepth -> DEBU 9fc[0m [core]Subchannel Connectivity change to SHUTDOWN
[31m2022-02-15 14:43:52.415 UTC 02d1 ERRO[0m [gateway] [31;1mlookupEndorser[0m -> Failed to reconnect endpoint=peer2.blockchainnp.company.com.co:443 err="failed to create new connection: connection error: desc = \"transport: error while dialing: dial tcp 10.250.37.121:443: connect: connection refused\""
[34m2022-02-15 14:43:52.415 UTC 02d2 INFO[0m [comm.grpc.server] [34;1m1[0m -> unary call completed grpc.service=gateway.Gateway grpc.method=Endorse grpc.request_deadline=2022-02-15T14:44:07.291Z grpc.peer_address=10.250.37.99:60228 grpc.peer_subject="CN=admin-tls@blockchainnp.company.com.co,OU=admin,O=company,L=MEDELLIN,ST=ANTIOQUIA,C=CO" grpc.code=OK grpc.call_duration=124.156979ms
[36m2022-02-15 14:43:52.613 UTC [grpc] WarningDepth -> DEBU 9fd[0m [core]Adjusting keepalive ping interval to minimum period of 10s
[36m2022-02-15 14:43:52.613 UTC [grpc] InfoDepth -> DEBU 9fe[0m [core]parsed scheme: ""
[36m2022-02-15 14:43:52.613 UTC [grpc] InfoDepth -> DEBU 9ff[0m [core]scheme "" not registered, fallback to default scheme
[36m2022-02-15 14:43:52.613 UTC [grpc] InfoDepth -> DEBU a00[0m [core]ccResolverWrapper: sending update to cc: {[{orderer1.blockchainnp.company.com.co:443  <nil> 0 <nil>}] <nil> <nil>}
[36m2022-02-15 14:43:52.613 UTC [grpc] InfoDepth -> DEBU a01[0m [core]ClientConn switching balancer to "pick_first"
[36m2022-02-15 14:43:52.613 UTC [grpc] InfoDepth -> DEBU a02[0m [core]Channel switches to new LB policy "pick_first"
[36m2022-02-15 14:43:52.613 UTC [grpc] InfoDepth -> DEBU a03[0m [core]Subchannel Connectivity change to CONNECTING
[36m2022-02-15 14:43:52.613 UTC [grpc] InfoDepth -> DEBU a04[0m [core]Subchannel picks a new address "orderer1.blockchainnp.company.com.co:443" to connect
[36m2022-02-15 14:43:52.614 UTC [grpc] InfoDepth -> DEBU a05[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc003f89de0, {CONNECTING <nil>}
[36m2022-02-15 14:43:52.614 UTC [grpc] InfoDepth -> DEBU a06[0m [core]Channel Connectivity change to CONNECTING
[36m2022-02-15 14:43:52.974 UTC [grpc] InfoDepth -> DEBU a07[0m [transport]transport: loopyWriter.run returning. connection error: desc = "transport is closing"
[36m2022-02-15 14:43:52.974 UTC [grpc] InfoDepth -> DEBU a08[0m [core]Subchannel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:43:52.974 UTC [grpc] InfoDepth -> DEBU a09[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc003f89de0, {TRANSIENT_FAILURE connection closed}
[36m2022-02-15 14:43:52.974 UTC [grpc] InfoDepth -> DEBU a0a[0m [core]Channel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:43:53.974 UTC [grpc] InfoDepth -> DEBU a0b[0m [core]Subchannel Connectivity change to CONNECTING
[36m2022-02-15 14:43:53.975 UTC [grpc] InfoDepth -> DEBU a0d[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc003f89de0, {CONNECTING <nil>}
[36m2022-02-15 14:43:53.975 UTC [grpc] InfoDepth -> DEBU a0e[0m [core]Channel Connectivity change to CONNECTING
[36m2022-02-15 14:43:53.974 UTC [grpc] InfoDepth -> DEBU a0c[0m [core]Subchannel picks a new address "orderer1.blockchainnp.company.com.co:443" to connect
[36m2022-02-15 14:43:54.101 UTC [grpc] InfoDepth -> DEBU a0f[0m [core]Subchannel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:43:54.101 UTC [grpc] InfoDepth -> DEBU a10[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc003f89de0, {TRANSIENT_FAILURE connection closed}
[36m2022-02-15 14:43:54.101 UTC [grpc] InfoDepth -> DEBU a11[0m [core]Channel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:43:54.101 UTC [grpc] InfoDepth -> DEBU a12[0m [transport]transport: loopyWriter.run returning. connection error: desc = "transport is closing"
[36m2022-02-15 14:43:55.870 UTC [grpc] InfoDepth -> DEBU a13[0m [core]Subchannel Connectivity change to CONNECTING
[36m2022-02-15 14:43:55.870 UTC [grpc] InfoDepth -> DEBU a14[0m [core]Subchannel picks a new address "orderer1.blockchainnp.company.com.co:443" to connect
[36m2022-02-15 14:43:55.870 UTC [grpc] InfoDepth -> DEBU a15[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc003f89de0, {CONNECTING <nil>}
[36m2022-02-15 14:43:55.872 UTC [grpc] InfoDepth -> DEBU a16[0m [core]Channel Connectivity change to CONNECTING
[36m2022-02-15 14:43:56.071 UTC [grpc] InfoDepth -> DEBU a17[0m [core]Subchannel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:43:56.072 UTC [grpc] InfoDepth -> DEBU a18[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc003f89de0, {TRANSIENT_FAILURE connection closed}
[36m2022-02-15 14:43:56.072 UTC [grpc] InfoDepth -> DEBU a19[0m [core]Channel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:43:56.071 UTC [grpc] InfoDepth -> DEBU a1a[0m [transport]transport: loopyWriter.run returning. connection error: desc = "transport is closing"
[36m2022-02-15 14:43:59.039 UTC [grpc] InfoDepth -> DEBU a1b[0m [core]Subchannel Connectivity change to CONNECTING
[36m2022-02-15 14:43:59.039 UTC [grpc] InfoDepth -> DEBU a1c[0m [core]Subchannel picks a new address "orderer1.blockchainnp.company.com.co:443" to connect
[36m2022-02-15 14:43:59.040 UTC [grpc] InfoDepth -> DEBU a1d[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc003f89de0, {CONNECTING <nil>}
[36m2022-02-15 14:43:59.040 UTC [grpc] InfoDepth -> DEBU a1e[0m [core]Channel Connectivity change to CONNECTING
[36m2022-02-15 14:43:59.068 UTC [grpc] InfoDepth -> DEBU a1f[0m [core]Subchannel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:43:59.068 UTC [grpc] InfoDepth -> DEBU a20[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc003f89de0, {TRANSIENT_FAILURE connection closed}
[36m2022-02-15 14:43:59.068 UTC [grpc] InfoDepth -> DEBU a21[0m [core]Channel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:43:59.070 UTC [grpc] InfoDepth -> DEBU a22[0m [transport]transport: loopyWriter.run returning. connection error: desc = "transport is closing"
[36m2022-02-15 14:44:03.536 UTC [grpc] InfoDepth -> DEBU a23[0m [core]Subchannel Connectivity change to CONNECTING
[36m2022-02-15 14:44:03.536 UTC [grpc] InfoDepth -> DEBU a24[0m [core]Subchannel picks a new address "orderer1.blockchainnp.company.com.co:443" to connect
[36m2022-02-15 14:44:03.536 UTC [grpc] InfoDepth -> DEBU a25[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc003f89de0, {CONNECTING <nil>}
[36m2022-02-15 14:44:03.536 UTC [grpc] InfoDepth -> DEBU a26[0m [core]Channel Connectivity change to CONNECTING
[36m2022-02-15 14:44:03.564 UTC [grpc] InfoDepth -> DEBU a27[0m [transport]transport: loopyWriter.run returning. connection error: desc = "transport is closing"
[36m2022-02-15 14:44:03.564 UTC [grpc] InfoDepth -> DEBU a28[0m [core]Subchannel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:03.564 UTC [grpc] InfoDepth -> DEBU a29[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc003f89de0, {TRANSIENT_FAILURE connection closed}
[36m2022-02-15 14:44:03.565 UTC [grpc] InfoDepth -> DEBU a2a[0m [core]Channel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:11.188 UTC [grpc] InfoDepth -> DEBU a2b[0m [core]Subchannel Connectivity change to CONNECTING
[36m2022-02-15 14:44:11.189 UTC [grpc] InfoDepth -> DEBU a2d[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc003f89de0, {CONNECTING <nil>}
[36m2022-02-15 14:44:11.189 UTC [grpc] InfoDepth -> DEBU a2e[0m [core]Channel Connectivity change to CONNECTING
[36m2022-02-15 14:44:11.189 UTC [grpc] InfoDepth -> DEBU a2c[0m [core]Subchannel picks a new address "orderer1.blockchainnp.company.com.co:443" to connect
[36m2022-02-15 14:44:11.221 UTC [grpc] InfoDepth -> DEBU a2f[0m [transport]transport: loopyWriter.run returning. connection error: desc = "transport is closing"
[36m2022-02-15 14:44:11.221 UTC [grpc] InfoDepth -> DEBU a30[0m [core]Subchannel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:11.221 UTC [grpc] InfoDepth -> DEBU a31[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc003f89de0, {TRANSIENT_FAILURE connection closed}
[36m2022-02-15 14:44:11.221 UTC [grpc] InfoDepth -> DEBU a32[0m [core]Channel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:22.075 UTC [grpc] InfoDepth -> DEBU a33[0m [core]Subchannel Connectivity change to CONNECTING
[36m2022-02-15 14:44:22.075 UTC [grpc] InfoDepth -> DEBU a34[0m [core]Subchannel picks a new address "orderer1.blockchainnp.company.com.co:443" to connect
[36m2022-02-15 14:44:22.076 UTC [grpc] InfoDepth -> DEBU a35[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc003f89de0, {CONNECTING <nil>}
[36m2022-02-15 14:44:22.076 UTC [grpc] InfoDepth -> DEBU a36[0m [core]Channel Connectivity change to CONNECTING
[36m2022-02-15 14:44:22.103 UTC [grpc] InfoDepth -> DEBU a37[0m [transport]transport: loopyWriter.run returning. connection error: desc = "transport is closing"
[36m2022-02-15 14:44:22.103 UTC [grpc] InfoDepth -> DEBU a38[0m [core]Subchannel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:22.103 UTC [grpc] InfoDepth -> DEBU a39[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc003f89de0, {TRANSIENT_FAILURE connection closed}
[36m2022-02-15 14:44:22.103 UTC [grpc] InfoDepth -> DEBU a3a[0m [core]Channel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:22.614 UTC [grpc] InfoDepth -> DEBU a3b[0m [core]Channel Connectivity change to SHUTDOWN
[36m2022-02-15 14:44:22.614 UTC [grpc] InfoDepth -> DEBU a3c[0m [core]Subchannel Connectivity change to SHUTDOWN
[33m2022-02-15 14:44:22.616 UTC 02d3 WARN[0m [gateway] [33;1morderers[0m -> Failed to connect to orderer address=orderer1.blockchainnp.company.com.co:443 err="failed to create new connection: context deadline exceeded"
[36m2022-02-15 14:44:22.617 UTC [grpc] WarningDepth -> DEBU a3d[0m [core]Adjusting keepalive ping interval to minimum period of 10s
[36m2022-02-15 14:44:22.619 UTC [grpc] InfoDepth -> DEBU a3e[0m [core]parsed scheme: ""
[36m2022-02-15 14:44:22.619 UTC [grpc] InfoDepth -> DEBU a3f[0m [core]scheme "" not registered, fallback to default scheme
[36m2022-02-15 14:44:22.620 UTC [grpc] InfoDepth -> DEBU a40[0m [core]ccResolverWrapper: sending update to cc: {[{orderer2.blockchainnp.company.com.co:443  <nil> 0 <nil>}] <nil> <nil>}
[36m2022-02-15 14:44:22.620 UTC [grpc] InfoDepth -> DEBU a41[0m [core]ClientConn switching balancer to "pick_first"
[36m2022-02-15 14:44:22.620 UTC [grpc] InfoDepth -> DEBU a42[0m [core]Channel switches to new LB policy "pick_first"
[36m2022-02-15 14:44:22.620 UTC [grpc] InfoDepth -> DEBU a43[0m [core]Subchannel Connectivity change to CONNECTING
[36m2022-02-15 14:44:22.620 UTC [grpc] InfoDepth -> DEBU a44[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc004a93380, {CONNECTING <nil>}
[36m2022-02-15 14:44:22.620 UTC [grpc] InfoDepth -> DEBU a45[0m [core]Channel Connectivity change to CONNECTING
[36m2022-02-15 14:44:22.620 UTC [grpc] InfoDepth -> DEBU a46[0m [core]Subchannel picks a new address "orderer2.blockchainnp.company.com.co:443" to connect
[36m2022-02-15 14:44:22.897 UTC [grpc] InfoDepth -> DEBU a47[0m [core]Subchannel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:22.897 UTC [grpc] InfoDepth -> DEBU a48[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc004a93380, {TRANSIENT_FAILURE connection closed}
[36m2022-02-15 14:44:22.897 UTC [grpc] InfoDepth -> DEBU a49[0m [core]Channel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:22.897 UTC [grpc] InfoDepth -> DEBU a4a[0m [transport]transport: loopyWriter.run returning. connection error: desc = "transport is closing"
[36m2022-02-15 14:44:23.898 UTC [grpc] InfoDepth -> DEBU a4b[0m [core]Subchannel Connectivity change to CONNECTING
[36m2022-02-15 14:44:23.898 UTC [grpc] InfoDepth -> DEBU a4c[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc004a93380, {CONNECTING <nil>}
[36m2022-02-15 14:44:23.898 UTC [grpc] InfoDepth -> DEBU a4d[0m [core]Subchannel picks a new address "orderer2.blockchainnp.company.com.co:443" to connect
[36m2022-02-15 14:44:23.898 UTC [grpc] InfoDepth -> DEBU a4e[0m [core]Channel Connectivity change to CONNECTING
[36m2022-02-15 14:44:24.000 UTC [grpc] InfoDepth -> DEBU a4f[0m [core]Subchannel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:24.000 UTC [grpc] InfoDepth -> DEBU a50[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc004a93380, {TRANSIENT_FAILURE connection closed}
[36m2022-02-15 14:44:24.001 UTC [grpc] InfoDepth -> DEBU a51[0m [core]Channel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:24.001 UTC [grpc] InfoDepth -> DEBU a52[0m [transport]transport: loopyWriter.run returning. connection error: desc = "transport is closing"
[36m2022-02-15 14:44:25.762 UTC [grpc] InfoDepth -> DEBU a53[0m [core]Subchannel Connectivity change to CONNECTING
[36m2022-02-15 14:44:25.762 UTC [grpc] InfoDepth -> DEBU a54[0m [core]Subchannel picks a new address "orderer2.blockchainnp.company.com.co:443" to connect
[36m2022-02-15 14:44:25.762 UTC [grpc] InfoDepth -> DEBU a55[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc004a93380, {CONNECTING <nil>}
[36m2022-02-15 14:44:25.763 UTC [grpc] InfoDepth -> DEBU a56[0m [core]Channel Connectivity change to CONNECTING
[36m2022-02-15 14:44:25.866 UTC [grpc] InfoDepth -> DEBU a57[0m [transport]transport: loopyWriter.run returning. connection error: desc = "transport is closing"
[36m2022-02-15 14:44:25.866 UTC [grpc] InfoDepth -> DEBU a58[0m [core]Subchannel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:25.866 UTC [grpc] InfoDepth -> DEBU a59[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc004a93380, {TRANSIENT_FAILURE connection closed}
[36m2022-02-15 14:44:25.866 UTC [grpc] InfoDepth -> DEBU a5a[0m [core]Channel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:28.781 UTC [grpc] InfoDepth -> DEBU a5b[0m [core]Subchannel Connectivity change to CONNECTING
[36m2022-02-15 14:44:28.781 UTC [grpc] InfoDepth -> DEBU a5c[0m [core]Subchannel picks a new address "orderer2.blockchainnp.company.com.co:443" to connect
[36m2022-02-15 14:44:28.781 UTC [grpc] InfoDepth -> DEBU a5d[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc004a93380, {CONNECTING <nil>}
[36m2022-02-15 14:44:28.782 UTC [grpc] InfoDepth -> DEBU a5e[0m [core]Channel Connectivity change to CONNECTING
[36m2022-02-15 14:44:28.805 UTC [grpc] InfoDepth -> DEBU a5f[0m [transport]transport: loopyWriter.run returning. connection error: desc = "transport is closing"
[36m2022-02-15 14:44:28.806 UTC [grpc] InfoDepth -> DEBU a60[0m [core]Subchannel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:28.806 UTC [grpc] InfoDepth -> DEBU a61[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc004a93380, {TRANSIENT_FAILURE connection closed}
[36m2022-02-15 14:44:28.806 UTC [grpc] InfoDepth -> DEBU a62[0m [core]Channel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:33.644 UTC [grpc] InfoDepth -> DEBU a63[0m [core]Subchannel Connectivity change to CONNECTING
[36m2022-02-15 14:44:33.644 UTC [grpc] InfoDepth -> DEBU a64[0m [core]Subchannel picks a new address "orderer2.blockchainnp.company.com.co:443" to connect
[36m2022-02-15 14:44:33.645 UTC [grpc] InfoDepth -> DEBU a65[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc004a93380, {CONNECTING <nil>}
[36m2022-02-15 14:44:33.645 UTC [grpc] InfoDepth -> DEBU a66[0m [core]Channel Connectivity change to CONNECTING
[36m2022-02-15 14:44:33.663 UTC [grpc] InfoDepth -> DEBU a67[0m [transport]transport: loopyWriter.run returning. connection error: desc = "transport is closing"
[36m2022-02-15 14:44:33.663 UTC [grpc] InfoDepth -> DEBU a68[0m [core]Subchannel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:33.663 UTC [grpc] InfoDepth -> DEBU a69[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc004a93380, {TRANSIENT_FAILURE connection closed}
[36m2022-02-15 14:44:33.663 UTC [grpc] InfoDepth -> DEBU a6a[0m [core]Channel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:40.384 UTC [grpc] InfoDepth -> DEBU a6b[0m [core]Subchannel Connectivity change to CONNECTING
[36m2022-02-15 14:44:40.384 UTC [grpc] InfoDepth -> DEBU a6c[0m [core]Subchannel picks a new address "orderer2.blockchainnp.company.com.co:443" to connect
[36m2022-02-15 14:44:40.384 UTC [grpc] InfoDepth -> DEBU a6d[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc004a93380, {CONNECTING <nil>}
[36m2022-02-15 14:44:40.384 UTC [grpc] InfoDepth -> DEBU a6e[0m [core]Channel Connectivity change to CONNECTING
[36m2022-02-15 14:44:40.407 UTC [grpc] InfoDepth -> DEBU a6f[0m [core]Subchannel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:40.407 UTC [grpc] InfoDepth -> DEBU a70[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc004a93380, {TRANSIENT_FAILURE connection closed}
[36m2022-02-15 14:44:40.407 UTC [grpc] InfoDepth -> DEBU a71[0m [core]Channel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:40.407 UTC [grpc] InfoDepth -> DEBU a72[0m [transport]transport: loopyWriter.run returning. connection error: desc = "transport is closing"
[36m2022-02-15 14:44:52.233 UTC [grpc] InfoDepth -> DEBU a73[0m [core]Subchannel Connectivity change to CONNECTING
[36m2022-02-15 14:44:52.233 UTC [grpc] InfoDepth -> DEBU a74[0m [core]Subchannel picks a new address "orderer2.blockchainnp.company.com.co:443" to connect
[36m2022-02-15 14:44:52.234 UTC [grpc] InfoDepth -> DEBU a75[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc004a93380, {CONNECTING <nil>}
[36m2022-02-15 14:44:52.235 UTC [grpc] InfoDepth -> DEBU a76[0m [core]Channel Connectivity change to CONNECTING
[36m2022-02-15 14:44:52.249 UTC [grpc] InfoDepth -> DEBU a77[0m [transport]transport: loopyWriter.run returning. connection error: desc = "transport is closing"
[36m2022-02-15 14:44:52.249 UTC [grpc] InfoDepth -> DEBU a78[0m [core]Subchannel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:52.249 UTC [grpc] InfoDepth -> DEBU a79[0m [core]pickfirstBalancer: UpdateSubConnState: 0xc004a93380, {TRANSIENT_FAILURE connection closed}
[36m2022-02-15 14:44:52.249 UTC [grpc] InfoDepth -> DEBU a7a[0m [core]Channel Connectivity change to TRANSIENT_FAILURE
[36m2022-02-15 14:44:52.619 UTC [grpc] InfoDepth -> DEBU a7b[0m [core]Channel Connectivity change to SHUTDOWN
[36m2022-02-15 14:44:52.619 UTC [grpc] InfoDepth -> DEBU a7c[0m [core]Subchannel Connectivity change to SHUTDOWN
[33m2022-02-15 14:44:52.622 UTC 02d4 WARN[0m [gateway] [33;1morderers[0m -> Failed to connect to orderer address=orderer2.blockchainnp.company.com.co:443 err="failed to create new connection: context deadline exceeded"
[34m2022-02-15 14:44:52.623 UTC 02d5 INFO[0m [comm.grpc.server] [34;1m1[0m -> unary call completed grpc.service=gateway.Gateway grpc.method=Submit grpc.request_deadline=2022-02-15T14:43:57.612Z grpc.peer_address=10.250.37.99:60228 grpc.peer_subject="CN=admin-tls@blockchainnp.company.com.co,OU=admin,O=company,L=MEDELLIN,ST=ANTIOQUIA,C=CO" error="rpc error: code = Unavailable desc = no orderer nodes available" grpc.code=Unavailable grpc.call_duration=1m0.010544106s
[36m2022-02-15 14:46:58.105 UTC [grpc] InfoDepth -> DEBU a7d[0m [transport]transport: loopyWriter.run returning. connection error: desc = "transport is closing"

These are the logs in the orderer:

[31m2022-02-15 14:43:52.971 UTC 022f ERRO[0m [core.comm] [31;1mServerHandshake[0m -> Server TLS handshake failed in 4.729309ms with error tls: client didn't provide a certificate server=Orderer remoteaddress=10.250.37.99:40274
[36m2022-02-15 14:43:52.971 UTC [grpc] WarningDepth -> DEBU 0c8[0m [core]grpc: Server.Serve failed to complete security handshake from "10.250.37.99:40274": tls: client didn't provide a certificate
[31m2022-02-15 14:43:54.098 UTC 0230 ERRO[0m [core.comm] [31;1mServerHandshake[0m -> Server TLS handshake failed in 3.966591ms with error tls: client didn't provide a certificate server=Orderer remoteaddress=10.250.37.99:40286
[36m2022-02-15 14:43:54.098 UTC [grpc] WarningDepth -> DEBU 0c9[0m [core]grpc: Server.Serve failed to complete security handshake from "10.250.37.99:40286": tls: client didn't provide a certificate
[31m2022-02-15 14:43:56.068 UTC 0231 ERRO[0m [core.comm] [31;1mServerHandshake[0m -> Server TLS handshake failed in 4.306991ms with error tls: client didn't provide a certificate server=Orderer remoteaddress=10.250.37.99:40316
[36m2022-02-15 14:43:56.068 UTC [grpc] WarningDepth -> DEBU 0ca[0m [core]grpc: Server.Serve failed to complete security handshake from "10.250.37.99:40316": tls: client didn't provide a certificate
[31m2022-02-15 14:43:59.065 UTC 0232 ERRO[0m [core.comm] [31;1mServerHandshake[0m -> Server TLS handshake failed in 5.948225ms with error tls: client didn't provide a certificate server=Orderer remoteaddress=10.250.37.99:40354
[36m2022-02-15 14:43:59.065 UTC [grpc] WarningDepth -> DEBU 0cb[0m [core]grpc: Server.Serve failed to complete security handshake from "10.250.37.99:40354": tls: client didn't provide a certificate
[31m2022-02-15 14:44:03.560 UTC 0233 ERRO[0m [core.comm] [31;1mServerHandshake[0m -> Server TLS handshake failed in 4.426394ms with error tls: client didn't provide a certificate server=Orderer remoteaddress=10.250.37.99:40404
[36m2022-02-15 14:44:03.560 UTC [grpc] WarningDepth -> DEBU 0cc[0m [core]grpc: Server.Serve failed to complete security handshake from "10.250.37.99:40404": tls: client didn't provide a certificate
[31m2022-02-15 14:44:11.218 UTC 0234 ERRO[0m [core.comm] [31;1mServerHandshake[0m -> Server TLS handshake failed in 4.068784ms with error tls: client didn't provide a certificate server=Orderer remoteaddress=10.250.37.99:40492
[36m2022-02-15 14:44:11.218 UTC [grpc] WarningDepth -> DEBU 0cd[0m [core]grpc: Server.Serve failed to complete security handshake from "10.250.37.99:40492": tls: client didn't provide a certificate
[31m2022-02-15 14:44:22.100 UTC 0235 ERRO[0m [core.comm] [31;1mServerHandshake[0m -> Server TLS handshake failed in 4.717598ms with error tls: client didn't provide a certificate server=Orderer remoteaddress=10.250.37.99:40612
[36m2022-02-15 14:44:22.100 UTC [grpc] WarningDepth -> DEBU 0ce[0m [core]grpc: Server.Serve failed to complete security handshake from "10.250.37.99:40612": tls: client didn't provide a certificate

I double checked and I do have a client certificate set on the grpc connection:

transportCredentials := credentials.NewTLS(&tls.Config{
	ServerName:   fabricConfig.HostName,
	RootCAs:      certPool,
	ClientCAs:    certPool,
	Certificates: []tls.Certificate{clientCert},
})

I guess the problem now is not with the ca certificates but still it doesn't work.

Thanks

@andrew-coleman
Copy link
Member

Ok, this looks like a separate problem. Currently the gateway does not support mutual TLS between the gateway server and other peers and orderer nodes:
https://github.com/hyperledger/fabric/blob/main/internal/pkg/gateway/endpoint.go#L100

This will need to be implemented. I'll raise a separate issue for this.

@afrancoc2000
Copy link
Contributor Author

Ok, thanks

@andrew-coleman
Copy link
Member

@afrancoc2000, the mutual TLS issue has been fixed and merged (#3234). Please could you let me know if this resolves the problem you were seeing? Thanks!

@afrancoc2000
Copy link
Contributor Author

@andrew-coleman with your last fix things started working! thanks!

@paweldzielak
Copy link

@afrancoc2000 the fix has been merged

Do not work for fabric 2.5.

docker exec -t cli.peer0.${ORG}.${DOMAIN} peer lifecycle chaincode commit --channelID common --name ${chaincodeName} --version 1.0 --sequence 2 --init-required --tls --tlsRootCertFiles $ORDERER_CA --peerAddresses peer0.${ORG}.${DOMAIN}:7051
2023-04-06 08:42:23.584 UTC [comm.tls] ClientHandshake -> ERRO 001 Client TLS handshake failed after 964.649µs with error: x509: certificate signed by unknown authority remoteaddress=172.20.0.12:7051
2023-04-06 08:42:24.601 UTC [comm.tls] ClientHandshake -> ERRO 002 Client TLS handshake failed after 12.660329ms with error: x509: certificate signed by unknown authority remoteaddress=172.20.0.12:7051
2023-04-06 08:42:26.047 UTC [comm.tls] ClientHandshake -> ERRO 003 Client TLS handshake failed after 2.160028ms with error: x509: certificate signed by unknown authority remoteaddress=172.20.0.12:7051
Error: failed to retrieve endorser client for commit: endorser client failed to connect to peer0.org1.example.com:7051: failed to create new connection: context deadline exceeded

@afrancoc2000
Copy link
Contributor Author

thanks!

@epewerner
Copy link

@afrancoc2000 the fix has been merged

Do not work for fabric 2.5.

docker exec -t cli.peer0.${ORG}.${DOMAIN} peer lifecycle chaincode commit --channelID common --name ${chaincodeName} --version 1.0 --sequence 2 --init-required --tls --tlsRootCertFiles $ORDERER_CA --peerAddresses peer0.${ORG}.${DOMAIN}:7051
2023-04-06 08:42:23.584 UTC [comm.tls] ClientHandshake -> ERRO 001 Client TLS handshake failed after 964.649µs with error: x509: certificate signed by unknown authority remoteaddress=172.20.0.12:7051
2023-04-06 08:42:24.601 UTC [comm.tls] ClientHandshake -> ERRO 002 Client TLS handshake failed after 12.660329ms with error: x509: certificate signed by unknown authority remoteaddress=172.20.0.12:7051
2023-04-06 08:42:26.047 UTC [comm.tls] ClientHandshake -> ERRO 003 Client TLS handshake failed after 2.160028ms with error: x509: certificate signed by unknown authority remoteaddress=172.20.0.12:7051
Error: failed to retrieve endorser client for commit: endorser client failed to connect to peer0.org1.example.com:7051: failed to create new connection: context deadline exceeded

Is there a solution for 2.5?

@bestbeforetoday
Copy link
Member

bestbeforetoday commented Jun 1, 2023

@paweldzielak @epewerner This issue describes a bug in the peer Gateway service implementation, preventing the Gateway service connecting to other nodes when intermediate TLS certificates are used. This has been fixed. You seem to be describing a similar bug in the peer lifecycle chaincode CLI command. It might be worth raising a separate issue for the CLI behaviour you are seeing. You can always reference this issue for information.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

7 participants