fabric-ca-server and AWS CloudHSM: TLS cert issues?

[theblop]

Hello,

I'm trying to setup a fabric-ca-server with AWS CloudHSM:

I use the library cloudhsm-pkcs11 v5.2.1-2 on ubuntu 18.04 (there are no more recent ubuntu versions supported by AWS cloudHSM at this time)

I configured a couple of HSM servers in an HSM cluster and added a "fabric" CU (Crypto User) with the aws HSM cli:

$ /opt/cloudhsm/bin/cloudhsm_mgmt_util /opt/cloudhsm/etc/cloudhsm_mgmt_util.cfg
aws-cloudhsm>loginHSM CO admin password
aws-cloudhsm>createUser CU fabric 12345678

I configured both fabric-ca-server-config.yaml and fabric-ca-client-config.yaml with:

bccsp:
  default: PKCS11
  pkcs11:
      Library: /opt/cloudhsm/lib/libcloudhsm_pkcs11.so
      Pin: 'fabric:12345678'
      AltId: FABRIC
      # it seems that the label must be the name of the HSM cluster in AWS:
      Label: cluster-dzetr75hznp
      hash: SHA2
      security: 256

I init the CA server (the MSP key is successfully stored in the HSM):

$ fabric-ca-server init -b admin:adminpw
2021/10/07 02:46:58 [INFO] Configuration file location: /opt/hsmtest/ca.hsm/rootca/fabric-ca-server-config.yaml
2021/10/07 02:46:59 [INFO] Server Version: 1.5.2
2021/10/07 02:46:59 [INFO] Server Levels: &{Identity:2 Affiliation:1 Certificate:1 Credential:1 RAInfo:1 Nonce:1}
2021/10/07 02:46:59 [WARNING] &{69 The specified CA certificate file /opt/hsmtest/ca.hsm/rootca/ca-cert.pem does not exist}
2021/10/07 02:46:59 [INFO] generating key: &{A:ecdsa S:256}
2021/10/07 02:46:59 [INFO] encoded CSR
2021/10/07 02:46:59 [INFO] signed certificate with serial number 457077676613156083610706603201870637828122354856
2021/10/07 02:46:59 [INFO] The CA key and certificate were generated for CA rootca
2021/10/07 02:46:59 [INFO] The key was stored by BCCSP provider 'PKCS11'
2021/10/07 02:46:59 [INFO] The certificate is at: /opt/hsmtest/ca.hsm/rootca/ca-cert.pem
2021/10/07 02:46:59 [INFO] Initialized sqlite3 database at /opt/hsmtest/ca.hsm/rootca/fabric-ca-server.db
2021/10/07 02:46:59 [INFO] The issuer key was successfully stored. The public key is at: /opt/hsmtest/ca.hsm/rootca/IssuerPublicKey, secret key is at: /opt/hsmtest/ca.hsm/rootca/msp/keystore/IssuerSecretKey
2021/10/07 02:46:59 [INFO] Idemix issuer revocation public and secret keys were generated for CA 'rootca'
2021/10/07 02:46:59 [INFO] The revocation key was successfully stored. The public key is at: /opt/hsmtest/ca.hsm/rootca/IssuerRevocationPublicKey, private key is at: /opt/hsmtest/ca.hsm/rootca/msp/keystore/IssuerRevocationPrivateKey
2021/10/07 02:46:59 [INFO] Home directory for default CA: /opt/hsmtest/ca.hsm/rootca
2021/10/07 02:46:59 [INFO] Initialization was successful

But then when I start the server, the TLS self-signed cert generation fails:

$ /etc/hyperledger/fabric-ca-client# fabric-ca-server start -d
2021/10/07 02:52:10 [DEBUG] Home directory: /opt/hsmtest/ca.hsm/rootca
2021/10/07 02:52:10 [INFO] Configuration file location: /opt/hsmtest/ca.hsm/rootca/fabric-ca-server-config.yaml
2021/10/07 02:52:10 [INFO] Starting server in home directory: /opt/hsmtest/ca.hsm/rootca
2021/10/07 02:52:10 [DEBUG] Set log level: 
2021/10/07 02:52:10 [INFO] Server Version: 1.5.2
2021/10/07 02:52:10 [INFO] Server Levels: &{Identity:2 Affiliation:1 Certificate:1 Credential:1 RAInfo:1 Nonce:1}
2021/10/07 02:52:10 [DEBUG] Making server filenames absolute
2021/10/07 02:52:10 [DEBUG] Initializing default CA in directory /opt/hsmtest/ca.hsm/rootca
2021/10/07 02:52:10 [DEBUG] CA Home Directory: /opt/hsmtest/ca.hsm/rootca
2021/10/07 02:52:10 [DEBUG] Checking configuration file version '1.4.7' against server version: '1.5.2'
2021/10/07 02:52:10 [DEBUG] Initializing BCCSP: &{ProviderName:PKCS11 SwOpts:0xc000394150 PluginOpts:<nil> Pkcs11Opts:0xc000143000}
2021/10/07 02:52:10 [DEBUG] Initializing BCCSP with software options &{SecLevel:256 HashFamily:SHA2 FileKeystore:0xc00016ccd0 DummyKeystore:<nil> InmemKeystore:<nil>}
2021/10/07 02:52:10 [DEBUG] Initializing BCCSP with PKCS11 options {SecLevel:256 HashFamily:SHA2 Ephemeral:false FileKeystore:<nil> DummyKeystore:<nil> Library:/opt/cloudhsm/lib/libcloudhsm_pkcs11.so Label:****** Pin:****** SoftVerify:false Immutable:false AltId:FABRIC}
2021/10/07 02:52:10 [DEBUG] Initialize key material
2021/10/07 02:52:10 [DEBUG] Making CA filenames absolute
2021/10/07 02:52:10 [INFO] The CA key and certificate already exist
2021/10/07 02:52:10 [INFO] The key is stored by BCCSP provider 'PKCS11'
2021/10/07 02:52:10 [INFO] The certificate is at: /opt/hsmtest/ca.hsm/rootca/ca-cert.pem
2021/10/07 02:52:10 [DEBUG] Loading CN from existing enrollment information
2021/10/07 02:52:10 [DEBUG] Initializing DB
2021/10/07 02:52:10 [DEBUG] Initializing 'sqlite3' database at '/opt/hsmtest/ca.hsm/rootca/fabric-ca-server.db'
2021/10/07 02:52:10 [DEBUG] Using sqlite database, connect to database in home (/opt/hsmtest/ca.hsm/rootca/fabric-ca-server.db) directory
2021/10/07 02:52:10 [DEBUG] Creating SQLite database (/opt/hsmtest/ca.hsm/rootca/fabric-ca-server.db) if it does not exist...
2021/10/07 02:52:10 [DEBUG] Creating users table if it does not exist
2021/10/07 02:52:10 [DEBUG] Creating affiliations table if it does not exist
2021/10/07 02:52:10 [DEBUG] Creating certificates table if it does not exist
2021/10/07 02:52:10 [DEBUG] Creating credentials table if it does not exist
2021/10/07 02:52:10 [DEBUG] Creating revocation_authority_info table if it does not exist
2021/10/07 02:52:10 [DEBUG] Creating nonces table if it does not exist
2021/10/07 02:52:10 [DEBUG] Creating properties table if it does not exist
2021/10/07 02:52:10 [DEBUG] Successfully opened sqlite3 DB
2021/10/07 02:52:10 [DEBUG] Initializing identity registry
2021/10/07 02:52:10 [DEBUG] Initialized DB identity registry
2021/10/07 02:52:10 [DEBUG] Checking database levels '&{Identity:2 Affiliation:1 Certificate:1 Credential:1 RAInfo:1 Nonce:1}' against server levels '&{Identity:2 Affiliation:1 Certificate:1 Credential:1 RAInfo:1 Nonce:1}'
2021/10/07 02:52:10 [DEBUG] Loading identity table
2021/10/07 02:52:10 [DEBUG] Loading identity 'admin_ca'
2021/10/07 02:52:10 [DEBUG] DB: Getting identity admin_ca
2021/10/07 02:52:10 [DEBUG] Identity 'admin_ca' already registered, loaded identity
2021/10/07 02:52:10 [DEBUG] Successfully loaded identity table
2021/10/07 02:52:10 [DEBUG] Loading affiliations table
2021/10/07 02:52:10 [DEBUG] Successfully loaded affiliations table
2021/10/07 02:52:10 [INFO] Initialized sqlite3 database at /opt/hsmtest/ca.hsm/rootca/fabric-ca-server.db
2021/10/07 02:52:10 [DEBUG] Initializing enrollment signer
2021/10/07 02:52:10 [DEBUG] validating configuration
2021/10/07 02:52:10 [DEBUG] validate local profile
2021/10/07 02:52:10 [DEBUG] profile is valid
2021/10/07 02:52:10 [DEBUG] validate local profile
2021/10/07 02:52:10 [DEBUG] profile is valid
2021/10/07 02:52:10 [DEBUG] validate local profile
2021/10/07 02:52:10 [DEBUG] profile is valid
2021/10/07 02:52:10 [DEBUG] CA initialization successful
2021/10/07 02:52:10 [DEBUG] Initializing Idemix issuer...
2021/10/07 02:52:10 [INFO] The Idemix issuer public and secret key files already exist
2021/10/07 02:52:10 [INFO]    secret key file location: /opt/hsmtest/ca.hsm/rootca/msp/keystore/IssuerSecretKey
2021/10/07 02:52:10 [INFO]    public key file location: /opt/hsmtest/ca.hsm/rootca/IssuerPublicKey
2021/10/07 02:52:10 [DEBUG] Intializing revocation authority for issuer 'rootca'
2021/10/07 02:52:10 [DEBUG] Initialize Idemix issuer revocation key material
2021/10/07 02:52:10 [INFO] The Idemix issuer revocation public and secret key files already exist
2021/10/07 02:52:10 [INFO]    private key file location: /opt/hsmtest/ca.hsm/rootca/msp/keystore/IssuerRevocationPrivateKey
2021/10/07 02:52:10 [INFO]    public key file location: /opt/hsmtest/ca.hsm/rootca/IssuerRevocationPublicKey
2021/10/07 02:52:10 [DEBUG] Intializing nonce manager for issuer 'rootca'
2021/10/07 02:52:10 [INFO] Home directory for default CA: /opt/hsmtest/ca.hsm/rootca
2021/10/07 02:52:10 [DEBUG] 1 CA instance(s) running on server
2021/10/07 02:52:10 [INFO] Operation Server Listening on 127.0.0.1:9443
2021/10/07 02:52:10 [DEBUG] TLS is enabled
2021/10/07 02:52:10 [DEBUG] TLS enabled but either certificate or key file does not exist, automatically generating TLS credentials
2021/10/07 02:52:10 [DEBUG] TLS CSR: {<PRIVATE STUFF>}
2021/10/07 02:52:10 [DEBUG] GenCSR &{<PRIVATE STUFF>}
2021/10/07 02:52:10 [DEBUG] Initializing client with config: &{URL: MSPDir: TLS:{Enabled:false CertFiles:[] Client:{KeyFile: CertFile:}} Enrollment:{ Name: Secret:**** CAName: AttrReqs:[] Profile: Label: CSR:<nil> Type:  } CSR:{CN: Names:[] Hosts:[] KeyRequest:<nil> CA:<nil> SerialNumber:} ID:{Name: Type: Secret: MaxEnrollments:0 Affiliation: Attributes:[] CAName:} Revoke:{Name: Serial: AKI: Reason: CAName: GenCRL:false} CAInfo:{CAName:} CAName: CSP:0xc000147fb0 Debug:false LogLevel:}
2021/10/07 02:52:10 [DEBUG] Initializing BCCSP: &{ProviderName:PKCS11 SwOpts:0xc000394150 PluginOpts:<nil> Pkcs11Opts:0xc000143000}
2021/10/07 02:52:10 [DEBUG] Initializing BCCSP with software options &{SecLevel:256 HashFamily:SHA2 FileKeystore:0xc00016ccd0 DummyKeystore:<nil> InmemKeystore:<nil>}
2021/10/07 02:52:10 [DEBUG] Initializing BCCSP with PKCS11 options {SecLevel:256 HashFamily:SHA2 Ephemeral:false FileKeystore:<nil> DummyKeystore:<nil> Library:/opt/cloudhsm/lib/libcloudhsm_pkcs11.so Label:****** Pin:****** SoftVerify:false Immutable:false AltId:FABRIC}
2021/10/07 02:52:10 [INFO] generating key: &{A:ecdsa S:256}
2021/10/07 02:52:10 [DEBUG] generate key from request: algo=ecdsa, size=256
2021/10/07 02:52:10 [DEBUG] failed generating BCCSP key: Failed generating ECDSA P256 key: P11: keypair generate failed [pkcs11: 0x13: CKR_ATTRIBUTE_VALUE_INVALID]
2021/10/07 02:52:10 [DEBUG] Closing server DBs
Error: Failed to automatically generate TLS certificate and key: Failed to generate CSR: Failed generating ECDSA P256 key: P11: keypair generate failed [pkcs11: 0x13: CKR_ATTRIBUTE_VALUE_INVALID]

Here is the corresponding cloudhsm log:

2021-10-07T02:52:10.204+02:00 INFO  [179] ThreadId(5) [cloudhsm_provider::hsm1::connection::connection_pool] Adding HSM connection to connection pool: HsmConnection { hsm_info: HSM { IP: "10.4.1.189", Port: 2223 } }
2021-10-07T02:52:10.209+02:00 INFO  [179] ThreadId(5) [cloudhsm_provider::hsm1::hsm_connection::server_connection::common] Initializing new connection: HSM { IP: "10.4.1.189", Port: 2223 }
2021-10-07T02:52:10.260+02:00 INFO  [179] ThreadId(5) [cloudhsm_provider::hsm1::hsm_connection::server_properties] Version handshake with server succeeded. Received version: ComponentVersion { major: 2, minor: 3 }
2021-10-07T02:52:10.260+02:00 INFO  [179] ThreadId(5) [hsm1_marshaling::server_handshake] Reporting sdk version Pkcs11:5.2-1-bionic:CodeBuildBatchProject-uFu5sNXfquqK:ed9a3dbd-7172-439f-8ee3-79408d4e3f39
2021-10-07T02:52:10.304+02:00 WARN  [179] ThreadId(3) [cloudhsm_provider::hsm1::hsm_connection::dispatcher_strategy] UX000: Discarding HSM response because it does not match a pending request.
2021-10-07T02:52:10.352+02:00 INFO  [179] ThreadId(5) [cloudhsm_provider::hsm1::connection::connection_pool] Adding HSM connection to connection pool: HsmConnection { hsm_info: HSM { IP: "10.4.1.236", Port: 2223 } }
2021-10-07T02:52:10.355+02:00 INFO  [179] ThreadId(5) [cloudhsm_provider::hsm1::hsm_connection::server_connection::common] Initializing new connection: HSM { IP: "10.4.1.236", Port: 2223 }
2021-10-07T02:52:10.401+02:00 INFO  [179] ThreadId(5) [cloudhsm_provider::hsm1::hsm_connection::server_properties] Version handshake with server succeeded. Received version: ComponentVersion { major: 2, minor: 3 }
2021-10-07T02:52:10.401+02:00 INFO  [179] ThreadId(5) [hsm1_marshaling::server_handshake] Reporting sdk version Pkcs11:5.2-1-bionic:CodeBuildBatchProject-uFu5sNXfquqK:ed9a3dbd-7172-439f-8ee3-79408d4e3f39
2021-10-07T02:52:10.444+02:00 WARN  [179] ThreadId(1) [cloudhsm_provider::hsm1::hsm_connection::dispatcher_strategy] UX000: Discarding HSM response because it does not match a pending request.
2021-10-07T02:52:10.492+02:00 INFO  [179] ThreadId(3) [cloudhsm_provider::hsm1::connection::connection_pool::cluster_info_message] Cluster version 150321984 is up to date. Ignoring cluster version received: 150321671.
2021-10-07T02:52:10.492+02:00 INFO  [179] ThreadId(5) [cloudhsm_provider::hsm1::connection::device] Retrieving HSM information.
2021-10-07T02:52:10.513+02:00 INFO  [179] ThreadId(5) [cloudhsm_provider::hsm1::connection::session_creation] Successfully created session with id: ProviderSessionId { inner: 1 }
2021-10-07T02:52:10.560+02:00 ERROR [179] ThreadId(6) [cloudhsm_pkcs11::general::C_Initialize] BP000: Library is already initialized.
2021-10-07T02:52:10.560+02:00 ERROR [179] ThreadId(6) [cloudhsm_pkcs11::general::C_Initialize] C_Initialize failed, returning 0x00000191
2021-10-07T02:52:10.560+02:00 INFO  [179] ThreadId(6) [cloudhsm_provider::hsm1::connection::device] Retrieving HSM information.
2021-10-07T02:52:10.581+02:00 INFO  [179] ThreadId(6) [cloudhsm_provider::hsm1::connection::session_creation] Successfully created session with id: ProviderSessionId { inner: 2 }
2021-10-07T02:52:10.582+02:00 ERROR [179] ThreadId(6) [cloudhsm_provider::hsm1::session::authentication] Failed to login to HSM. 2 connections failed, out of 2. Returning first error from HSM { IP: "10.4.1.236", Port: 2223 }, AlreadyLoggedIn.
2021-10-07T02:52:10.582+02:00 ERROR [179] ThreadId(6) [cloudhsm_pkcs11::session::C_Login] Error: User is already logged in
2021-10-07T02:52:10.582+02:00 ERROR [179] ThreadId(6) [cloudhsm_pkcs11::session::C_Login] C_Login failed, returning 0x00000100
2021-10-07T02:52:10.587+02:00 ERROR [179] ThreadId(6) [cloudhsm_pkcs11::keymgmt::C_GenerateKeyPair::error] Attribute Value for (Unknown) is invalid
2021-10-07T02:52:10.587+02:00 ERROR [179] ThreadId(6) [cloudhsm_pkcs11::keymgmt::C_GenerateKeyPair] C_GenerateKeyPair failed, returning 0x00000013

I had no problem with the TLS cert generation with the softhsm driver, so maybe the problem with AWS is the AltId setting which is the same here for the generated MSP CA cert and the TLS cert? Also I don't really know what to make of the "Error: User is already logged in" in the cloudhsm log...

[denyeart]

@davidkel this one goes with https://github.com/hyperledger/fabric/issues/2972

[davidkel]

I don't think you can use an HSM to store TLS certificates because it's not the fabric code base that does the TLS Handling (and that code base won't try to communicate with the HSM) so you should generate the fabric-ca-server TLS certificates yourself (not using the HSM) and reference those, otherwise it looks like fabric-ca-server attempts to generate them via the BCCSP which is configured for PKCS11 and fails because it tries to register with an identical ID and IDs must be unique.

[theblop]

@davidkel indeed this is what I suspected and reported in https://github.com/hyperledger/fabric/issues/2972#issuecomment-937543866

This is obviously not ideal to have to generate the TLS certs outside of fabric-ca-server when using PKCS11 instead of the SW BCCSP, especially since the error isn't so obvious with softhsm which doesn't need AltId and doesn't fail immediately on the TLS cert generation step. Could this possibly be documented clearly in the doc here https://hyperledger-fabric-ca.readthedocs.io/en/v1.5.0/users-guide.html#configuring-an-hsm to avoid frustration for other poor souls stuck with AWS CloudHSM ? :)

[davidkel]

@theblop Using an HSM for TLS certs is not possible both in fabric and fabric-ca, and if it isn't documented in either then I agree it should be. I'll add a comment back to hyperledger/fabric#2972 to also include this information in the fabric docs as well if it isn't there

[theblop]

Now I'm trying to generate a separate TLS cert for fabric-ca-server with openssl, the server starts but I get "certificate signed by unknown authority" from fabric-ca-client (I set --tls.certfiles to point to the openssl self signed cert). With openssl -connect I get a "bad record MAC" error.

Now maybe the TLS cert has to be signed by the ca-cert generated by fabric-ca-server init? In that case I can't see how it's possible to use AWS CloudHSM at all with fabric-ca...

[denyeart]

What do you think @davidkel ?

[mastersingh24]

Seems like there are a couple of different issues here:

1) It is true that the TLS stack in fabric and fabric-ca does not support PKCS11. So you need to have the key and cert files to start the TLS server.

2) It appears that the path to generate the TLS server cert for fabric-ca-server attempts to use the configured crypto provider rather than using the SW provider to generate the TLS cert. See https://github.com/hyperledger/fabric-ca/blob/v1.5.2/lib/server.go#L861

3) Need to check why the fabric-ca-client does not support trusting self-signed certificates. Typically they will be signed by a CA, but self-signed should work.

[davidkel]

I wonder if it's possible to work around this by first bringing up a fabric-ca-server in SW mode to generate the TLS key and cert, then change the config to PKCS11 and re-bring up the fabric-ca-server ?

[lakshaygaur]

Im trying to register and enroll peer identities running a fabric-ca container with SW mode. But fabric-ca-client is failing with the same error as in this issue. Error: Failure generating CSR: Failed generating ECDSA P256 key: P11: keypair generate failed [pkcs11: 0x13: CKR_ATTRIBUTE_VALUE_INVALID]