hyperledger-archives / fabric

THIS IS A READ-ONLY historic repository. Current development is at https://gerrit.hyperledger.org/r/#/admin/projects/fabric . pull requests not accepted
https://gerrit.hyperledger.org/
Apache License 2.0
1.17k stars 1.01k forks source link

Cannot use TLS upon first startup of a node with security turned on #926

Open harrijk opened 8 years ago

harrijk commented 8 years ago

I believe that the following issue is procedural in nature. During the few weeks that I have been working with openblockchain and trying to understand the functionality of the major components, I stumbled upon the observation outlined below.

The first time that you start an OBC peer with security enabled, you must ensure that the other security settings within the openchain.yaml file are set to false: security.privacy, peer.tls.enabled, peer.pki.tls.enabled, and vm.docker.tls.enabled. If other security settings are enabled other than the security.enabled flag, peer startup errors will occur in attempts to access certificates that have not yet been generated. All of the required certificates and keys for the peer are generated the first time that the peer is started with the security.enabled flag set to true within the openchain.yaml file.

Here is an example of what happens when you startup a peer for the first time with security.enabled=true and peer.pki.tls.enabled=true: The peer.pki.tls.rootcert.file parameter was set to: /var/openchain/production/.obcca/tlsca.cert

From the obcca-server log: 2016/03/31 12:25:54 transport: http2Server.HandleStreams received bogus greeting from client: "\x16\x03\x01\x00\x9a\x01\x00\x00\x96\x03\x03\xd9Pv]\x91p\\|I\xb2\xe3\x8b\xed" 2016/03/31 12:25:55 transport: http2Server.HandleStreams received bogus greeting from client: "\x16\x03\x01\x00\x9a\x01\x00\x00\x96\x03\x03\x86\xe6\xe0\xf2+5+\xdfrT\xe5\x88m" 2016/03/31 12:25:56 transport: http2Server.HandleStreams received bogus greeting from client: "\x16\x03\x01\x00\x9a\x01\x00\x00\x96\x03\x03\xfd,(\xd0ν\xcf\x0es}\x05ʿ"

From the obc-peer log: 12:25:54.073 [main] serve -> INFO 005 Security enabled status: true 12:25:54.073 [main] serve -> INFO 006 Privacy enabled status: false 12:25:54.073 [eventhub_producer] start -> INFO 007 event processor started 12:25:54.073 [main] serve -> DEBU 008 Running as validating peer - installing consensus noops 12:25:54.074 [peer] NewPeerWithHandler -> DEBU 009 Registering validator with enroll ID: test_vp0 12:25:54.074 [CRYPTO] RegisterValidator -> INFO 00a Registering validator [test_vp0] with name [test_vp0]... 12:25:54.074 [CRYPTO.validator.test_vp0] register -> INFO 00b Registering [test_vp0]... 12:25:54.074 [CRYPTO.validator.test_vp0] register -> INFO 00c Init keystore... 12:25:54.074 [CRYPTO.validator.test_vp0] createKeyStoreIfNotExists -> DEBU 00d Keystore path [/var/openchain/production/crypto/validator/test_vp0/ks] missing [true]: [<clean>] 12:25:54.074 [CRYPTO.validator.test_vp0] createKeyStore -> DEBU 00e Creating Keystore at [/var/openchain/production/crypto/validator/test_vp0/ks]... 12:25:54.075 [CRYPTO.validator.test_vp0] createKeyStore -> DEBU 00f Open Keystore DB... 12:25:54.075 [CRYPTO.validator.test_vp0] createKeyStore -> DEBU 010 Ping Keystore DB... 12:25:54.075 [CRYPTO.validator.test_vp0] createKeyStore -> DEBU 011 Keystore created at [/var/openchain/production/crypto/validator/test_vp0/ks]. 12:25:54.075 [CRYPTO.validator.test_vp0] openKeyStore -> DEBU 012 Open keystore at [/var/openchain/production/crypto/validator/test_vp0/ks]... 12:25:54.075 [CRYPTO.validator.test_vp0] openKeyStore -> DEBU 013 Open keystore at [/var/openchain/production/crypto/validator/test_vp0/ks]...done 12:25:54.075 [CRYPTO.validator.test_vp0] register -> INFO 014 Init keystore...done. 12:25:54.075 [CRYPTO.validator.test_vp0] registerCryptoEngine -> INFO 015 Registering node crypto engine... 12:25:54.075 [CRYPTO.validator.test_vp0] initTLS -> DEBU 016 Initiliazing TLS... 12:25:54.075 [CRYPTO.validator.test_vp0] loadExternalCert -> DEBU 017 Loading external certificate at [/var/openchain/production/.obcca/tlsca.cert]... 12:25:54.076 [CRYPTO.validator.test_vp0] initTLS -> DEBU 018 Initiliazing TLS...Done 12:25:54.076 [CRYPTO.validator.test_vp0] getECAClient -> DEBU 019 Getting ECA client... 12:25:54.076 [CRYPTO.validator.test_vp0] getClientConn -> DEBU 01a Getting Client Connection to [tlsca]... 12:25:54.076 [CRYPTO.validator.test_vp0] getClientConn -> DEBU 01b TLS enabled... 12:25:54.076 [CRYPTO.validator.test_vp0] getClientConn -> DEBU 01c Getting Client Connection to [tlsca]...done 12:25:54.076 [CRYPTO.validator.test_vp0] getECAClient -> DEBU 01d Getting ECA client...done 2016/03/31 12:25:55 grpc: ClientConn.resetTransport failed to create client transport: connection error: desc = "transport: tls: first record does not look like a TLS handshake"; Reconnecting to "localhost:50051" 2016/03/31 12:25:56 grpc: ClientConn.resetTransport failed to create client transport: connection error: desc = "transport: tls: first record does not look like a TLS handshake"; Reconnecting to "localhost:50051" 2016/03/31 12:25:56 Failed to dial localhost:50051: grpc: timed out trying to connect; please retry. 12:25:56.744 [CRYPTO.validator.test_vp0] callECAReadCACertificate -> ERRO 01e Failed requesting read certificate [rpc error: code = 2 desc = "grpc: the client connection is closing"]. 12:25:56.744 [CRYPTO.validator.test_vp0] getECACertificate -> ERRO 01f Failed requesting ECA certificate [rpc error: code = 2 desc = "grpc: the client connection is closing"]. 12:25:56.744 [CRYPTO.validator.test_vp0] retrieveECACertsChain -> ERRO 020 Failed getting ECA certificate [rpc error: code = 2 desc = "grpc: the client connection is closing"]. 12:25:56.744 [CRYPTO.validator.test_vp0] registerCryptoEngine -> ERRO 021 Failed retrieveing ECA certs chain [rpc error: code = 2 desc = "grpc: the client connection is closing"]. 12:25:56.744 [CRYPTO.validator.test_vp0] register -> ERRO 022 Failed registering crypto engine [rpc error: code = 2 desc = "grpc: the client connection is closing"]. 12:25:56.744 [CRYPTO] register -> ERRO 023 Failed registering [test_vp0]: [rpc error: code = 2 desc = "grpc: the client connection is closing"] 12:25:56.744 [CRYPTO] register -> ERRO 024 Failed registering [test_vp0]: [rpc error: code = 2 desc = "grpc: the client connection is closing"] 12:25:56.744 [CRYPTO] RegisterValidator -> ERRO 025 Failed registering validator [test_vp0] with name [test_vp0] [rpc error: code = 2 desc = "grpc: the client connection is closing"].

After the peer has generated the necessary certificates and keys upon its first startup, additional security parameters can be enabled. However, a restart of the peer is required to enable to additional security features.

adecaro commented 8 years ago

@binhn Is this planned to be fixed in the current sprint?

JonathanLevi commented 8 years ago

Will take a look at this too along with Diego. Thanks.