hyperledger / hyperledger/fabric-ca
fabric-ca-server and AWS CloudHSM: TLS cert issues?
- Dominant language
- Go
- Stars
- 453
- Forks
- 714
- Avg merge
- 7h 23m
- Merged PRs (30d)
- 3
Description
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: Pkcs11Opts:0xc000143000}
2021/10/07 02:52:10 [DEBUG] Initializing BCCSP with software options &{SecLevel:256 HashFamily:SHA2 FileKeystore:0xc00016ccd0 DummyKeystore: InmemKeystore:}
2021/10/07 02:52:10 [DEBUG] Initializing BCCSP with PKCS11 options {SecLevel:256 HashFamily:SHA2 Ephemeral:false FileKeystore: DummyKeystore: 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: {}
2021/10/07 02:52:10 [DEBUG] GenCSR &{}
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: Type: } CSR:{CN: Names:[] Hosts:[] KeyRequest: CA: 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: Pkcs11Opts:0xc000143000}
2021/10/07 02:52:10 [DEBUG] Initializing BCCSP with software options &{SecLevel:256 HashFamily:SHA2 FileKeystore:0xc00016ccd0 DummyKeystore: InmemKeystore:}
2021/10/07 02:52:10 [DEBUG] Initializing BCCSP with PKCS11 options {SecLevel:256 HashFamily:SHA2 Ephemeral:false FileKeystore: DummyKeystore: 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...
Contributor guide
Assessment
This issue has not been assessed yet.